## 背景 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 為： ~~~ #0 my_write #1 0x0000000000a92f50 in inline_mysql_file_write #2 0x0000000000a9612e in my_b_flush_io_cache #3 0x0000000000a43466 in MYSQL_BIN_LOG::flush_cache_to_file #4 0x0000000000a43a4d in MYSQL_BIN_LOG::ordered_commit #5 0x0000000000a429f2 in MYSQL_BIN_LOG::commit #6 0x000000000063d3e2 in ha_commit_trans #7 0x00000000008adb7a in trans_commit_stmt #8 0x00000000007e511f in mysql_execute_command #9 0x00000000007e7e0e in mysql_parse #10 0x00000000007dae0e in dispatch_command #11 0x00000000007d9634 in do_command #12 0x00000000007a046d in do_handle_one_connection #13 0x000000000079ff75 in handle_one_connection #14 0x0000003a00a07851 in start_thread () #15 0x0000003a006e767d in clone () ~~~ commit 時，會判斷是否將產生的 binlog flush 到文件中，即執行 fsync操作，詳細bt 為： ~~~ #0 MYSQL_BIN_LOG::sync_binlog_file #1 0x0000000000a43c62 in MYSQL_BIN_LOG::ordered_commit #2 0x0000000000a429f2 in MYSQL_BIN_LOG::commit #3 0x000000000063d3e2 in ha_commit_trans #4 0x00000000008adb7a in trans_commit_stmt #5 0x00000000007e511f in mysql_execute_command #6 0x00000000007e7e0e in mysql_parse #7 0x00000000007dae0e in dispatch_command #8 0x00000000007d9634 in do_command (thd=0x37a40160) #9 0x00000000007a046d in do_handle_one_connection #10 0x000000000079ff75 in handle_one_connection #11 0x0000003a00a07851 in start_thread () #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 如下： ~~~ #0 Rpl_info_table::do_flush_info (this=0x379cbf90, force=false) #1 0x0000000000a78270 in Rpl_info_handler::flush_info #2 0x0000000000a773b9 in Master_info::flush_info #3 0x0000000000a5da4b in flush_master_info #4 0x0000000000a697eb in handle_slave_io #5 0x0000003a00a07851 in start_thread () from /lib64/libpthread.so.0 #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](http://bugs.mysql.com/bug.php?id=72794) bug 原因: 備庫異常 crash 后，可能造成事務在拉取過程中被重新拉取，binlog序列如下： ~~~ begin; table_map; begin; table_map; rows_log_event; commit; ~~~ 在并行復制條件下，由于出現了不完整的事務，所以會造成綁定事務信息無法恢復，造成hang的情況，詳情見?[bug 分析](http://bugs.mysql.com/bug.php?id=72794)。 問題 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 協議，會在下期月報分析。