背景

MySQL 非 GTID 协议主备同步原理： 主库在执行 SQL 语句时产生binlog，在事务 commit 时将产生的binlog event写入binlog文件，备库IO线程通过 com_binlog_dump 用文件位置协议从主库拉取 binlog，将拉取的binlog存储到relaylog, SQL线程读取 relaylog 然后进行 apply，实现主备同步，在这个过程中有以下几个问题：

  1. 主库什么时间将产生的 binlog 真正刷到文件中？
  2. 备库IO线程从哪个位置读取主库的 binlog event 的？
  3. 备库SQL线程如何记录执行到的 relaylog 的位点？
  4. 备库IO线程何时将cache中的event 刷到relay log 文件中的?

问题分析

下面对这几个问题挨个解答。

问题 1: 主库什么时间将产生的binlog 真正刷到文件中

事务ordered_commit 中，会将 thd->cache_mngr 中的 binlog cache 写入到 binlog 文件中，但并没有执行fsync()操作，即只将文件内容写入到 OS 缓存中，详细 bt 为：

  1. #0  my_write
  2. #1  0x0000000000a92f50 in inline_mysql_file_write
  3. #2  0x0000000000a9612e in my_b_flush_io_cache
  4. #3  0x0000000000a43466 in MYSQL_BIN_LOG::flush_cache_to_file
  5. #4  0x0000000000a43a4d in MYSQL_BIN_LOG::ordered_commit
  6. #5  0x0000000000a429f2 in MYSQL_BIN_LOG::commit
  7. #6  0x000000000063d3e2 in ha_commit_trans
  8. #7  0x00000000008adb7a in trans_commit_stmt
  9. #8  0x00000000007e511f in mysql_execute_command
  10. #9  0x00000000007e7e0e in mysql_parse
  11. #10 0x00000000007dae0e in dispatch_command
  12. #11 0x00000000007d9634 in do_command
  13. #12 0x00000000007a046d in do_handle_one_connection
  14. #13 0x000000000079ff75 in handle_one_connection
  15. #14 0x0000003a00a07851 in start_thread ()
  16. #15 0x0000003a006e767d in clone ()

commit 时，会判断是否将产生的 binlog flush 到文件中，即执行 fsync操作，详细bt 为：

  1. #0  MYSQL_BIN_LOG::sync_binlog_file
  2. #1  0x0000000000a43c62 in MYSQL_BIN_LOG::ordered_commit
  3. #2  0x0000000000a429f2 in MYSQL_BIN_LOG::commit
  4. #3  0x000000000063d3e2 in ha_commit_trans
  5. #4  0x00000000008adb7a in trans_commit_stmt
  6. #5  0x00000000007e511f in mysql_execute_command
  7. #6  0x00000000007e7e0e in mysql_parse
  8. #7  0x00000000007dae0e in dispatch_command
  9. #8  0x00000000007d9634 in do_command (thd=0x37a40160)
  10. #9  0x00000000007a046d in do_handle_one_connection
  11. #10 0x000000000079ff75 in handle_one_connection
  12. #11 0x0000003a00a07851 in start_thread ()
  13. #12 0x0000003a006e767d in clone ()

由 MYSQL_BIN_LOG::sync_binlog_file 可以看出，每提交一个事务，会 fsync 一次binlog file。 当 sync_binlog != 1 的时候，每次事务提交的时候，不一定会执行 fsync 操作，binlog 的内容只是缓存在了 OS（是否会执行fsync操作，取决于OS缓存的大小），此时备库可以读到主库产生的 binlog, 在这种情况下，当主库机器挂掉时，有以下两种情况：

  1. 主备同步无延迟，此时主库机器恢复后，备库接着之前的位点重新拉binlog, 但是主库由于没有fsync最后的binlog，所以会返回1236 的错误： MySQL error code 1236 (ER_MASTER_FATAL_ERROR_READING_BINLOG): Got fatal error %d from master when reading data from binary log: '%-.256s'
  2. 备库没有读到主库失去的binlog，此时备库无法同步主库最后的更新，备库不可用。

问题 2: 备库IO线程从哪个位置读取主库的binlog event 的

更新位点信息的 bt 如下：

  1. #0  Rpl_info_table::do_flush_info (this=0x379cbf90, force=false)
  2. #1  0x0000000000a78270 in Rpl_info_handler::flush_info
  3. #2  0x0000000000a773b9 in Master_info::flush_info
  4. #3  0x0000000000a5da4b in flush_master_info
  5. #4  0x0000000000a697eb in handle_slave_io
  6. #5  0x0000003a00a07851 in start_thread () from /lib64/libpthread.so.0
  7. #6  0x0000003a006e767d in clone () from /lib64/libc.so.6

备库通过 master_log_info 来记录主库的相关信息，通过参数 sync_master_info 来设置备库经过多少个 binlog event 来更新已经读取到的位点信息。当stop slave时，会把正常的位点更新到master_log_info中，此时，如果最后的位点不是commit，则在start slave后，会继续上一位点拉取 binlog，从而造成同一个事务的binlog event分布在不同的binlog file中，此时如果执行顺利则不会有问题；如果在拉这个事务的过程中，sql 线程出错中断，在并行复制下会引起分发线程停在事务中间，再次启动的时候，会从上一次分发的事务继续分发，会造成在并行复制中不可分发的情况，因此需要注意。

当 sync_master_info > 1000时，可能在第1000个binlog 拉取的时候机器出问题，此时重启后会从主库多拉999个 binlog event，造成事务在备库多次执行问题，对于没有 primary key, unique key 可能会有问题，造成主备数据不一致，最常遇到的是1062问题。

问题3: 备库SQL线程如何记录执行到的relaylog 的位点

同问题2一样，相关的 bt 也类似，relay_log_info 记录的是备库已经执行了的最后的位点，这个位点不会处于事务中间，即是每 sync_relay_log_info 个事务更新一下这个位点。

相关bugs bug 原因: 备库异常 crash 后，可能造成事务在拉取过程中被重新拉取，binlog序列如下：

  1. begin;
  2. table_map;
  3. begin;
  4. table_map;
  5. rows_log_event;
  6. commit;

在并行复制条件下，由于出现了不完整的事务，所以会造成绑定事务信息无法恢复，造成hang的情况，详情见 bug 分析。

问题 4: 备库IO线程何时将cache中的event 刷到relay log 文件中的

这个问题的解答和问题1类似，也是以binlog event为单位的，当然也存在着和问题1中同样的问题，在此不在赘述。

结语

MySQL 通过 sync_binlog，sync_master_info，sync_relay_log_info，sync_relay_log 来记录相关的位点信息，出于性能考虑以及程序本身的健壮性，引入了各式要样的bug，类似的bug在此不在列举，那么有没有更好的方法来记录这些信息呢，当然有，即GTID 协议，会在下期月报分析。