MySQL:5.6大事務show engine innodb status故障一例

文章末尾有他著作的《深入理解 MySQL 主從原理 32 講》,深入透徹理解 MySQL 主從,GTID 相關技術知識。

(作者簡書:https://www.jianshu.com/p/40bef28e84cf)


背景

今天遇到一個朋友的線上問題,大概意思就是說,我有一個線上的大事務大概 100G 左右,正在做回滾,當前看起來似乎影響了線上的業務,並且回滾很慢,是否可以減輕對線上業務的影響。並且朋友已經取消了雙 1 設置,但是沒有任何改觀。

版本:MySQL 5.6

首先我們需要知道的是,MySQL 並不適合大事務,大概列舉一些 MySQL 中大事務的影響:

  • binlog 文件作為一次寫入,會在 sync 階段消耗大量的 IO,會導致全庫 hang 主,狀態大多為 query end。
  • 大事務會造成導致主從延遲。
  • 大事務可能導致某些需要備份掛起,原因在於 flush table with read lock,拿不到 MDL GLOBAL 級別的鎖,等待狀態為 Waiting for global read lock。
  • 大事務可能導致更大 Innodb row 鎖加鎖範圍,導致 row 鎖等待問題。
  • 回滾困難。

基於如上一些不完全的列舉,我們應該在線上儘可能的避免大事務。好了我們下面來進行問題討論。


分析

一、問題

前面已經說了,我們已經取消了雙 1 設置,所謂的雙 1 就是 sync_binlog=1 和 innodb_flush_log_at_trx_commit=1。這兩個參數線上要保證為 1,前者保證 binlog 的安全,後者保證 redo 的安全,它們在數據庫 crash recovery 的時候起到了關鍵作用,不設置為雙 1 可能導致數據丟失。具體的參數含義不做過多討論。但是這裡的問題是即便取消了雙 1,沒有任何改觀,因此似乎說明 IO問題不是主要瓶頸呢?

下面我們來看幾個截圖:

  • vmstat 截圖


故障分析 | MySQL:5.6大事務show engine innodb status故障一例

  • iostat 截圖


故障分析 | MySQL:5.6大事務show engine innodb status故障一例

  • top -Hu截圖


故障分析 | MySQL:5.6大事務show engine innodb status故障一例

我們重點觀察 vmstat 的 r 和 b 列發現,IO 隊列沒有什麼問題,並且 wa% 並不大。我們觀察 iostat 中的 %util 和讀寫數據大小來看問題不大,並且 tps 遠沒達到極限(SSD 盤)。我們 top -Hu 可以觀察到 %us 不小,並且有線程已經打滿了(99.4%CPU)一個 CPU 核。

因此我們可以將方向轉為研究 CPU 瓶頸的產生,希望能夠對問題有幫助,然後從提供的 perf top 中我們有如下發現:


故障分析 | MySQL:5.6大事務show engine innodb status故障一例


好了我們將問題先鎖定到 lock_number_of_rows_locked 這個函數上。


二、函數 lock_number_of_rows_locked 的作用

朋友用的 5.6,但是我這裡以 5.7.26 的版本進行描述。然後下一節描述 5.6 和 5.7 算法上的關鍵差異。

不知道大家是否注意過 show engine innodb status 中的這樣一個標誌:


故障分析 | MySQL:5.6大事務show engine innodb status故障一例


這個標記就來自函數 lock_number_of_rows_locked,含義為當前事務加行鎖的行數。而這個函數包裹在函數 lock_print_info

_all_transactions 下面,lock_print_info_all_transactions 函數是打印我們通常看到 show engine innodb status 中事務部分的核心參數。我們來看一下簡單的流程:

<code>PrintNotStarted print_not_started(file);//建立一個結構體,目的是做not start 事務的打印ut_list_map(trx_sys->mysql_trx_list, print_not_started); //這個地方打印出那些事務狀態是no start的事務。mysql_trx_list是全事務。consttrx_t* trx;TrxListIterator trx_iter; //這個迭代器是trx_sys->rw_trx_list 這個鏈表的迭代器consttrx_t* prev_trx = 0;/* Control whether a block should be fetched from the buffer pool. */bool load_block = true;bool monitor = srv_print_innodb_lock_monitor && (srv_show_locks_held != 0);while((trx = trx_iter.current()) != 0) { //通過迭代器進行迭代 ,顯然這裡不會有隻讀事務的信息,全部是讀寫事務。.../* If we need to print the locked record contents then weneed to fetch the containing block from the buffer pool. */if(monitor) {/* Print the locks owned by the current transaction. */TrxLockIterator& lock_iter = trx_iter.lock_iter();if(!lock_trx_print_locks( //打印出鎖的詳細信息file, trx, lock_iter, load_block))/<code>

簡單的說就是先打印哪些處於 not start 的事務,然後打印那些讀寫事務的信息,當然我們的回滾事務肯定也包含在其中了,需要注意的是隻讀事務 show engine 不會打印。對於處於回滾狀態的事務我們可以在 show engine 中觀察到如下信息:


故障分析 | MySQL:5.6大事務show engine innodb status故障一例


函數 trx_print_low 可以看到大部分的信息,這裡就不詳細解釋了。既然如此我們需要明白 lock_number_of_rows_locked 是如何計算的,下面進行討論。


三、函數 lock_number_of_rows_locked 的算法變化

上面我們說了函數 lock_number_of_rows_locked 函數會打印出當前事務加行鎖的行數。那麼我們來看一下 5.6 和 5.7 算法的不同。

5.7.26

實際上只有如下一句話:

<code>return(trx_lock->n_rec_locks);/<code>

我們可以看到這是返回了一個計數器,而這個計數器的遞增就是在每行記錄加鎖後完成的,在函數 lock_rec_set_nth_bit 的末尾可以看到 ++lock->trx->lock.nreclocks,因此這是一種預先計算的機制。

因此這樣的計算代價很低,也不會由於某個事務持有了大量的鎖,而導致計算代價過高。

5.6.22

隨後我翻了一下 5.6.22 的代碼,發現完全不同如下:

<code>for(lock= UT_LIST_GET_FIRST(trx_lock->trx_locks); //使用for循環每個獲取的鎖結構lock!= NULL;lock= UT_LIST_GET_NEXT(trx_locks, lock)) {if(lock_get_type_low(lock) == LOCK_REC) { //過濾為行鎖ulint n_bit;ulint n_bits = lock_rec_get_n_bits(lock);for(n_bit = 0; n_bit < n_bits; n_bit++) {//開始循環每一個鎖結構的每一個bit位進行統計if(lock_rec_get_nth_bit(lock, n_bit)) {n_records++;}}}}return(n_records);/<code>

我們知道循環本身是一種 CPU 密集型的操作,這裡使用了嵌套循環實現。因此如果在 5.6 中如果出現大事務操作了大量的行,那麼獲取行鎖記錄的個數的時候,將會出現高耗 CPU 的情況。


四、原因總結和解決

有了上面的分析我們很清楚了,觸發的原因有如下幾點:

  • MySQL 5.6 版本
  • 有大事務的存在,大概 100G 左右的數據加行鎖了
  • 使用了 show engine innodb status

這樣當在統計這個大事務行鎖個數的時候,就會進行大量的循環操作。從現象上看就是線程消耗了大量的 CPU 資源,並且處於 perf top 的第一位。

知道了原因就很簡單了,找出為頻繁使用 show engine innodb status 的監控工具,隨後業務全部恢復正常,IO 利用率也上升瞭如下:


故障分析 | MySQL:5.6大事務show engine innodb status故障一例


當然如果能夠使用更新的版本比如 5.7 及 8.0 版本將不會出現這個問題,可以考慮使用更高版本。

分析性能問題需要首先找到性能的瓶頸然後進行集中突破,比如本例中 CPU 資源消耗更加嚴重。也許解決問題就在一瞬間。


五、其他

最後通過朋友後面查詢的 bug 如下:https://bugs.mysql.com/bug.php?id=68647 發現印風(翟衛翔)已經在多年前提出過了這個問題,並且做出了修改意見,並且這個修改意見官方採納了,也就是上面我們分析的算法改變。經過印風(翟衛翔)的測試有 bug 中有如下描述:

  • From perf top, function locknumberofrowslocked may occupy more than 20% of CPU sometimes

也就是 CPU 消耗會高達 20%。

下面是 5.7.26 調用棧幀:


故障分析 | MySQL:5.6大事務show engine innodb status故障一例


最後推薦高鵬的專欄《深入理解 MySQL 主從原理 32 講》,想要透徹瞭解學習 MySQL 主從原理的朋友不容錯過。


分享到:


相關文章: