導(dǎo)讀：
作者：高鵬（網(wǎng)名八怪），《深入理解MySQL主從原理32講》系列文的作者。

今天遇到一個朋友的線上問題，大概意思就是說，我有一個線上的大事務(wù)大概100G左右，正在做回滾，當(dāng)前看起來似乎影響了線上的業(yè)務(wù)，并且回滾很慢，是否可以減輕對線上業(yè)務(wù)的影響。并且朋友已經(jīng)取消了雙1設(shè)置，但是沒有任何改觀。版本MySQL 5.6首先我們需要知道的是，MySQL并不適合大事務(wù)，大概列舉一些MySQL中大事務(wù)的影響：

• binlog文件作為一次寫入，會在sync階段消耗大量的IO，會導(dǎo)致全庫hang主，狀態(tài)大多為query end。

• 大事務(wù)會造成導(dǎo)致主從延遲。

• 大事務(wù)可能導(dǎo)致某些需要備份掛起，原因在于flush table with read lock，拿不到MDL GLOBAL 級別的鎖，等待狀態(tài)為 Waiting for global read lock。

• 大事務(wù)可能導(dǎo)致更大Innodb row鎖加鎖范圍，導(dǎo)致row鎖等待問題。

• 回滾困難。

基于如上一些不完全的列舉，我們應(yīng)該在線上盡可能的避免大事務(wù)。好了我們下面來進(jìn)行問題討論。

一、問題
前面已經(jīng)說了，我們已經(jīng)取消了雙1設(shè)置，所謂的雙1就是 sync_binlog=1和 innodb_flush_log_at_trx_commit=1。這兩個參數(shù)線上要保證為1，前者保證binlog的安全，后者保證redo的安全，它們在數(shù)據(jù)庫crash recovery的時候起到了關(guān)鍵做用，不設(shè)置為雙1可能導(dǎo)致數(shù)據(jù)丟失。具體的參數(shù)含義不做過多討論。但是這里的問題是即便取消了雙1，沒有任何改觀，因此似乎說明IO問題不是主要瓶頸呢？下面我們來看幾個截圖：

• vmstat 截圖

image

• iostat 截圖

image

image

• top -Hu截圖

image

我們重點(diǎn)觀察vmstat的r 和 b列發(fā)現(xiàn)，IO隊(duì)列沒有有什么問題 并且wa%并不大。我們觀察iostat中的%util和讀寫數(shù)據(jù)大小來看問題不大，并且tps遠(yuǎn)沒達(dá)到極限（SSD盤）。我們top -Hu 可以觀察到 %us不小，并且有線程已經(jīng)打滿了（99.4%CPU）一個CPU核。
因此我們可以將方向轉(zhuǎn)為研究CPU瓶頸的產(chǎn)生，希望能夠?qū)栴}有幫助，然后從提供的perf top中我們有如下發(fā)現(xiàn)：

image

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

二、函數(shù)lock_number_of_rows_locked的作用
朋友用的5.6，但是我這里以5.7.26的版本進(jìn)行描述。然后下一節(jié)描述5.6和5.7算法上的關(guān)鍵差異。不知道大家是否注意過show engine innodb status中的這樣一個標(biāo)志：

image

這個標(biāo)記就來自函數(shù)lock_number_of_rows_locked，含義為當(dāng)前事務(wù)加行鎖的行數(shù)。而這個函數(shù)包裹在函數(shù)lock_print_info_all_transactions下面，lock_print_info_all_transactions函數(shù)是打印我們通?？吹絪how engine innodb status中事務(wù)部分的核心參數(shù)。我們來看一下簡單的流程：

PrintNotStarted print_not_started(file);//建立一個結(jié)構(gòu)體，目的是做not start 事務(wù)的打印
ut_list_map(trx_sys->mysql_trx_list, print_not_started);  //這個地方打印出那些事務(wù)狀態(tài)是no start的事務(wù)。mysql_trx_list是全事務(wù)。
const  trx_t* trx;
TrxListIterator trx_iter;  //這個迭代器是trx_sys->rw_trx_list 這個鏈表的迭代器
const  trx_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)  {  //通過迭代器進(jìn)行迭代 ，顯然這里不會有只讀事務(wù)的信息，全部是讀寫事務(wù)。
   ...
    /* If we need to print the locked record contents then we
    need 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(  //打印出鎖的詳細(xì)信息
                  file, trx, lock_iter, load_block))

簡單的說就是先打印哪些處于not start的事務(wù)，然后打印那些讀寫事務(wù)的信息，當(dāng)然我們的回滾事務(wù)肯定也包含在其中了，需要注意的是只讀事務(wù)show engine不會打印。對于處于回滾狀態(tài)的事務(wù)我們可以在show engine中觀察到如下信息：

image

函數(shù)trx_print_low可以看到大部分的信息，這里就不詳細(xì)解釋了。既然如此我們需要明白lock_number_of_rows_locked是如何計(jì)算的，下面進(jìn)行討論。
三、函數(shù)lock_number_of_rows_locked的算法變化
上面我們說了函數(shù)lock_number_of_rows_locked函數(shù)會打印出當(dāng)前事務(wù)加行鎖的行數(shù)。那么我們來看一下5.6和5.7算法的不同。

• 5.7.26

實(shí)際上只有如下一句話：

return(trx_lock->n_rec_locks);

我們可以看到這是返回了一個計(jì)數(shù)器，而這個計(jì)數(shù)器的遞增就是在每行記錄加鎖后完成的，在函數(shù)lock_rec_set_nth_bit的末尾可以看到 ++lock->trx->lock.nreclocks ，因此這是一種預(yù)先計(jì)算的機(jī)制。因此這樣的計(jì)算代價很低，也不會由于某個事務(wù)持有了大量的鎖，而導(dǎo)致計(jì)算代價過高。

• 5.6.22

隨后我翻了一下5.6.22的代碼，發(fā)現(xiàn)完全不同如下：

for  (lock  = UT_LIST_GET_FIRST(trx_lock->trx_locks);  //使用for循環(huán)每個獲取的鎖結(jié)構(gòu)
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++)  {//開始循環(huán)每一個鎖結(jié)構(gòu)的每一個bit位進(jìn)行統(tǒng)計(jì)
              if  (lock_rec_get_nth_bit(lock, n_bit))  {
                   n_records++;
              }
         }
    }
}
return(n_records);

我們知道循環(huán)本身是一種CPU密集型的操作，這里使用了嵌套循環(huán)實(shí)現(xiàn)。因此如果在5.6中如果出現(xiàn)大事務(wù)操作了大量的行，那么獲取行鎖記錄的個數(shù)的時候，將會出現(xiàn)高耗CPU的情況。
四、原因總結(jié)和解決
有了上面的分析我們很清楚了，觸發(fā)的原因有如下幾點(diǎn)：

• MySQL 5.6版本

• 有大事務(wù)的存在，大概100G左右的數(shù)據(jù)加行鎖了

• 使用了show engine innodb status

這樣當(dāng)在統(tǒng)計(jì)這個大事務(wù)行鎖個數(shù)的時候，就會進(jìn)行大量的循環(huán)操作。從現(xiàn)象上看就是線程消耗了大量的CPU資源，并且處于perf top的第一位。

知道了原因就很簡單了，找出為頻繁使用show engine innodb status的監(jiān)控工具，隨后業(yè)務(wù)全部恢復(fù)正常，IO利用率也上升了如下：

image

當(dāng)然如果能夠使用更新的版本比如5.7及8.0 版本將不會出現(xiàn)這個問題，可以考慮使用更高版本。分析性能問題需要首先找到性能的瓶頸然后進(jìn)行集中突破，比如本例中CPU資源消耗更加嚴(yán)重。也許解決問題就在一瞬間。
五、其他
最后通過朋友后面查詢的bug如下：https://bugs.mysql.com/bug.php?id=68647發(fā)現(xiàn)印風(fēng)（翟衛(wèi)翔）已經(jīng)在多年前提出過了這個問題，并且做出了修改意見，并且這個修改意見官方采納了，也就是上面我們分析的算法改變。經(jīng)過印風(fēng)（翟衛(wèi)翔）的測試有bug中有如下描述：

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

也就是CPU消耗會高達(dá)20%。

下面是5.7.26調(diào)用棧幀：

image