共計 4678 個字符，預計需要花費 12 分鐘才能閱讀完成。
為什么在 MySQL 雙主單寫的情況下主庫偶爾出現大量延遲，相信很多沒有經驗的人對此束手無策，為此本文總結了問題出現的原因和解決方法，通過這篇文章希望你能解決這個問題。
我們是雙主單寫，這里約定寫入的庫為主庫，沒有寫入的庫為從庫。我們的 falcon 偶爾會進行報警如下（頻率很低）：
這是非常奇怪的，按理說我是單寫的從庫沒有做任何操作（除了應用 Event 以外），主庫哪來的延遲，并且延遲這么大。在我映像中有朋友問過這個問題，當時沒有細細研究。
二、延遲計算的規則
我們還是要看看主從計算延遲的偽代碼：
/*
The pseudo code to compute Seconds_Behind_Master:
if (SQL thread is running)
// 如果 SQL 線程啟動了
{ if (SQL thread processed all the available relay log)
// 如果 SQL 線程已經應用完了所有的 IO 線程寫入的 Event
{ if (IO thread is running)
// 如果 IO 線程啟動了
print 0;
// 設置延遲為 0
else
print NULL;
// 否則為空值
}
else
compute Seconds_Behind_Master;
// 如果 SQL 線程沒有應用完所有的 IO 線程寫入的 Event，那么需要計算延遲。 }
else
print NULL;
// 如果連 SQL 線程也沒有啟動則設置為空值
*/計算延遲的公式為：
long time_diff= ((long)(time(0)
- mi- rli- last_master_timestamp)
- mi- clock_diff_with_master);
服務器當前時間 -Event header 中的 timestamp - 主從服務器時間差出現延遲的必要條件：
如果 SQL 線程沒有應用完了所有的 IO 線程寫入的 Event，也就是 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 存在一定的差值。判定標準為
(mi- get_master_log_pos() == mi- rli- get_group_master_log_pos())
(!strcmp(mi- get_master_log_name(), mi- rli- get_group_master_log_name()))拋開文件名，也就是通過 IO 線程讀取到主庫 binary log 的位置 和 SQL 線程應用到的主庫 binary log 位置進行比較來進行 判斷，只要他們出現差值就會進入延遲計算環節。
服務器當前時間 -Event header 中的 timestamp – 主從服務器時間差 這個公式必須出現差值。
好了接下來帶著這兩個產生延遲的必要條件來尋求原因。
三、產生延遲的原因
1. 主庫：首先主庫寫到從庫的 Event，從庫會寫入到 binlog（log_slave_updates 開啟），并且從庫的 DUMP 線程會發送給主庫，但是主庫的 IO 線程通過 SERVER_ID 進程判定，將 Event 進行過濾，不寫入主庫的 relay log，同時會更新主庫 IO 線程讀取的位置（Read_Master_Log_Pos），并且更新忽略到的位置（rli- ign_master_log_name_end[0]）。代碼如下：
if (!(s_id == ::server_id !mi- rli- replicate_same_server_id) ||
(event_type != binary_log::FORMAT_DESCRIPTION_EVENT
event_type != binary_log::ROTATE_EVENT
event_type != binary_log::STOP_EVENT))
{ mi- set_master_log_pos(mi- get_master_log_pos() + inc_pos);// 增加 Read_Master_Log_Pos 位點，為當前位置
memcpy(rli- ign_master_log_name_end, mi- get_master_log_name(), FN_REFLEN); // 進行拷貝
DBUG_ASSERT(rli- ign_master_log_name_end[0]); // 斷言存在
rli- ign_master_log_pos_end= mi- get_master_log_pos(); // 忽略到位點
}主庫：SQL 線程會通過 rli- ign_master_log_name_end[0]判定是否有需要跳過的 Event，如果有則構建一個 Rotate_log_event 來跳過這個 Event，代碼如下：
if (rli- ign_master_log_name_end[0]) // 如果跳過的 Event 存在
{
/* We generate and return a Rotate, to make our positions advance */
DBUG_PRINT(info ,( seeing an ignored end segment));
ev= new Rotate_log_event(rli- ign_master_log_name_end,
0, rli- ign_master_log_pos_end, exec_relay_log_event
Rotate_log_event::DUP_NAME); // 構建一個 Rotate Event，位置為
rli- ign_master_log_name_end[0]= 0; //rli- ign_master_log_pos_end，執行這個 Event 就可以
mysql_mutex_unlock(log_lock);exec_relay_log_event // 來更新 Exec_Master_Log_Pos 位點
if (unlikely(!ev))
{
errmsg= Slave SQL thread failed to create a Rotate event
(out of memory?), SHOW SLAVE STATUS may be inaccurate
goto err;
}
ev- server_id= 0; // don t be ignored by slave SQL thread
DBUG_RETURN(ev);
}好了到這里我們知道了 Event 在主庫是如何跳過的，但是注意 IO 線程和 SQL 線程在處理 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 的時候可能有一定的時間差，那么 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 存在一定的差值 的條件就可能會滿足，則進入延遲計算環節。
主庫的 SQL 線程平時并沒有讀取到 Event，因為所有的 Event 都被 IO 線程過濾掉了。因此
Event 的 header 中的 timestamp 不會更新（MTS）。但是如果從庫 binlog 切換的時候，從庫至少會傳送 ROTATE_EVENT 給主庫，這個時候主庫會拿到這個實際的 Event，因此 Event 的 header 中的 timestamp 更新了。如果剛好遇到主庫的 IO 線程的 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 有差值，
那么 falcon 去查看延遲就會得到一個延遲很大的假象，延遲的計算公式就會變為如下：
主庫當前的時候 – 從庫上次 binlog 切換的時間 – 主從時間的差值
MTS 和單線程的不同
上面的第 3 點只適用于 MTS，單 SQL 線程不同，會去將 last_master_timestamp 設置為 0，代碼如下：
if (!rli- is_parallel_exec())
rli- last_master_timestamp= 0;言外之意單 SQL 線程計算延遲的公式為：
主庫當前的時間 – 1970 年 1 月 1 日 0 點 – 主從時間的差值
因此看起來計算出來的延遲會更大。
最后需要注意的是實際上這種情況的延遲并沒有問題，完全是一種偶爾出現的計算上的問題，是一種假象，如果主庫的壓力越大出現這種情況的可能性就會越大，因為 IO 線程和 SQL 線程在處理 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 的出現時間差的可能性就會越大。
四、MTS 下的延遲 debug
其實知道了原理就很容易 debug 了，因為我們可以將斷點放到主庫的 show_slave_status_send_data 函數上，那么就能看出來了，做的操作如下：
從庫 flush binary logs
主庫執行一些 insert 操作
主庫 show slave status
這個時候我們可以跳過（Read_Master_Log_Pos 和 Exec_Master_Log_Pos 存在一定的差值）這個條件，直接通過公式去計算，得到如下結果：
(gdb) p (long)(time(0)- mi- rli- last_master_timestamp)- mi- clock_diff_with_master
$6 = 37延遲就是 37 秒，因此我們的理論得到了驗證。
下面一個 debug 結果是單 SQL 線程的，可以看到延遲更是大得離譜。
(gdb) p (long)(time(0)- mi- rli- last_master_timestamp)- mi- clock_diff_with_master
$7 = 1592672402五、其他問題
額外的問題：
如果雙主雙寫
S1S2
T1T2
T3
如果按照上面的理論那么 T3 的更新的位置可能會被，T2 事務的位點重置。因為主庫的 SQL 線程通過構建的 Rotate_log_event 可能會出現 Exec_Master_Log_Pos 倒退的可能性，這顯然是不行的。但是代碼中構建 Rotate_log_event 的邏輯包裹在如下邏輯下面。
if (!cur_log- error) /* EOF */ // 當前 relay log 已經讀取完了
{
/*
On a hot log, EOF means that there are no more updates to
process and we must block until I/O thread adds some and
signals us to continue
*/
if (hot_log) // 如果是 當前 relay log我們可以看到只有在當前 relay log 讀取完成后才會進行 Rotate_log_event 的構建。因此不存在此問題。
問題如上雖然不構建 Rotate_log_event，但是如果 rli- ign_master_log_name_end[0]如果一直保留那么當 relay log 應用完成后，依舊會去構建 Rotate_log_event 導致 Exec_Master_Log_Pos 倒退，實際上這個問題也不會出現，因為在每次 IO 線程 Event 寫入到 relay log 后會重置，如下：
rli- ign_master_log_name_end[0]= 0; // last event is not ignored看完上述內容，你們掌握為什么在 MySQL 雙主單寫的情況下主庫偶爾出現大量延遲的方法了嗎？如果還想學到更多技能或想了解更多相關內容，歡迎關注丸趣 TV 行業資訊頻道，感謝各位的閱讀！
