說真的,這個主從延遲你還真處理不了




本文作者:張松坡,騰訊雲數據庫架構師,主要負責騰訊雲數據庫MySQL、Redis等數據庫架構設計、數據庫運維、運營開發等工作。曾就職於騰訊新聞、騰訊視頻。

寫在前面,感謝騰訊雲數據庫架構師團隊祝海強、杜川、劉志祥在排障思路、源碼分析上面提供的幫助,讓我學習到了很多,不敢居功,特此鳴謝!

本文將以數據庫實際使用中的某典型案例來分析造成主從延遲的原因。

主從延遲的原因

1、某用戶在使用數據庫過程中,出現主從延遲很大的情況,show slave status\\G,已經差了60多個binlog了。

說真的,這個主從延遲你還真處理不了

2、觀察發現,應該是卡在一個大事物上面(Retrieved_Gtid_Set一直在上升,但是Executed_Gtid_Set卡在一個點不動了),通過分析relay_log找到這個大事物:是對錶A進行刪除操作的一個事物。

<code>Relay_Log_File: relay-bin.000010Relay_Log_Pos: 95133771/<code>
說真的,這個主從延遲你還真處理不了

看到這裡,感覺又是一例在ROW模式下表沒有主鍵,引起的主從延遲。看看錶結構確認一下,發現這張表不小,字段有上百個,有主鍵,且是一張分區表,分區很多。這就有意思了!並不是我們碰到過多次的由於ROW模式下沒有主鍵,DML引起的主從延遲(PS:為什麼這種情況下會引起延遲?而是有主鍵,且走了二級索引,那為什麼回放還會這麼慢呢?)。

說真的,這個主從延遲你還真處理不了

後來瞭解到用戶是在存儲過程裡面調用detele語句來進行歸檔數據清理,看了一下存儲過程,現在的問題就可以簡化為:

在存儲過程中調用delete語句,走了二級索引刪除有主鍵的分區表,從機回放延遲。

說真的,這個主從延遲你還真處理不了

這個時候,我們需要拆解一下問題,控制好變量,一個一個的查:

1、直接執行delete,SQL會以statement的格式出現,且不會產生主從延遲。

說真的,這個主從延遲你還真處理不了

2、調用procedure,該delete語句在procedure中執行的時候會變成ROW格式,且會導致延遲。

OK,有以上兩個測試,我們的問題可以聚焦為:

1、為什麼同樣delete語句,直接執行和在procedure裡面執行記錄的binlog格式不一樣(ROW格式的binlog導致回放慢,全局設置在mixed模式下,這條SQL應該走的是statement格式,為什麼在procedure裡執行就變成了ROW格式,怎麼樣才能讓這條SQL再procedure裡執行變成statement記錄到binlog裡面)。

<code>delete from xxxxxwhere update_datetime < DATE_ADD(B_DATE,INTERVAL -1 day)and DATE_FORMAT(update_datetime,'%i') not in ('00','05','10','15','20','25','30');/<code>
說真的,這個主從延遲你還真處理不了

通過show processlist,可以看到這條delete在procedure內部執行的時候,被MySQL自動加上了NAME_CONST函數,所以導致了以ROW模式記錄binlog格式。那為什麼在procedure中會被改寫成這樣的SQL呢?怎麼樣才能讓這條SQL記錄為statement的格式呢?

說真的,這個主從延遲你還真處理不了

看了MySQL官方在procedure裡面的限制描述,MySQL會自動加上NAME_CONST主要是為了從機可以識別到B_DATE這個SP的Local vairable,不至於從機回放的時候報錯。

2、為什麼ROW模式的binlog在從庫回放的時候,即使delete的這張表有主鍵也很慢。

我們先看一下SQL線程回放是卡在哪裡了?為什麼會慢?

通過pstack抓取堆棧,找到SQL_thread線程對應的thread 15,再結合perf信息,可以看到從機回放慢是卡在了bitmap_get_next_set()。

說真的,這個主從延遲你還真處理不了

說真的,這個主從延遲你還真處理不了

看一下bitmap_get_next_set()的代碼。

bitmap_get_next_set()都是一些位運算,速度按理來說應該很快。所以不應該是程序卡在了這個函數中,大概率是因為多次調用了這個函數。所以我們再往上層繼續看代碼。

說真的,這個主從延遲你還真處理不了

get_next_used_partition(uint part_id) 直接調用了bitmap_get_next_set(),繼續往上看。

說真的,這個主從延遲你還真處理不了

try_semi_consistent_read() 這個函數中出現了可疑的循環,這裡會調用m_tot_parts次get_next_used_partition。看了一下定義m_tot_parts是分區表的總分區數!!!

看到這裡,就真相大白了。

這個delele的SQL變更的行數大約在300W行左右,總共的分區表數是7200個。那麼這裡調用bitmap_get_next_set的次數就被放大成了216億次!

說真的,這個主從延遲你還真處理不了

說真的,這個主從延遲你還真處理不了

對比以statement格式回放,從機的堆棧信息,並不會進入bitmap_get_next_set。

說真的,這個主從延遲你還真處理不了

解決方案

分析了這麼久,怎麼處理這麼問題呢?

  • 方案1:我們最後在SP中強制制定了session的binlog_format=statement,讓這條delete在從機以statement的模式回放,這樣就避免觸發MySQL中的這個bug。
  • 方案2:修復內核。
  • 方案3:在shell裡面去調度,而不使用存儲過程。


分享到:


相關文章: