記一次服務器執行MySQL耗時問題

MySQL對我說「Too young, too naive!"

---

大概過程

在測試環境Docker容器中，在跨進程調用服務的時候，A應用經過Dubbo調用B應用的RPC接口，發現B應用接口超時錯誤，接着經過debug和日誌，發現具體耗時的地方在於一句簡單SQL執行，可是耗時超過1000ms。

經過查看數據庫的進程列表，發現是有死鎖鎖表了，不少進程狀態status處於'sending data'，最後爲鎖住的表添加索引，而且kill掉阻塞的請求，解除死鎖，服務速度恢復正常。

---

下面記錄的是跟祥哥一塊兒的大體排查過程：

經過觀察業務代碼，確認沒有內存溢出或者其它事務問題，因而只能考慮Docker環境的數據庫和jvm底層詳情了。

使用Druid監控SQL執行狀態

經過日誌，發現有一句SQL嚴重超時，一句簡單SQL，本來是批量插入多條記錄，爲了定位問題，測試時Mybatis只插入一條記錄，但即使如此，仍是耗時10秒

因而打算使用阿里巴巴的數據庫鏈接池Druid進行監控，這篇文章有教如何使用Druid監控SQL執行狀態，監控SQL效果以下：

在SQL監控Tab中，能夠看到執行SQL的具體狀況，包括某條SQL語句執行的時間（平均、最慢）、SQL執行次數、SQL執行出錯的次數等

上面顯示的是正常狀況下，時間單位是ms，正常的SQL通常在10ms以內，數據量大的控制在30ms以內，這樣用戶的使用體驗感纔會良好。因此說以前的1000ms，是不可接受的結果。

---

經過JMC遠程監控Tomcat

JMC(java mission control)是jdk自帶的一個監控工具，在jdk的bin目錄下（java大法好，該目錄下有不少實用的工具）。

具體要怎麼配置和加的參數請參考此文

爲了簡單，我加了一個tomcat無驗證模式：

#在tomcat的conf目錄下的catalina.sh增長以下java啓動參數： 
-Dcom.sun.management.jmxremote=true
-Dcom.sun.management.jmxremote.port=8888
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder
複製代碼

下面是本身本地調試的截圖

而後打開jmc，建立一個JMX鏈接，輸入對應的ip和JMX端口。接着能夠設定一段時間內的飛行監控，監測這一分鐘內jvm具體參數

當時調試的時候，發現內存使用、CPU佔用率、線程狀態也挺正常的，沒有發現明顯的異常錯誤，效果以下圖：

惟一比較耗時的是在代碼tab頁中，當時發現了大量的I/O，比上圖的比例還高，當時大概佔了80%，查看調用樹，不少循環tcp socket鏈接，考慮到應用中原本就有不少須要io以及netty也須要tcp鏈接，因此大概排除了jvm虛擬機的問題，而後就去排查MySQL的問題。

---

排查MySQL

在瞭解MySQL鎖概念的時候，能夠參考這篇文章mysql什麼狀況下會觸發表鎖，因爲如今使用的比較多的是InnoDB，因此能夠着重看看InnoDB鎖問題。

直接執行SQL語句

經過DEBUG代碼，從mybatis中取出映射後的SQL語句，在MySQL客戶款直接執行SQL和Explain查看執行計劃，速度都很快，排除了SQL語句的問題。

查看MySQL線程列表

show processlist;
複製代碼

從圖中能夠看出，有些線程的狀態處於sending data，查閱資料：所謂的「Sending data」並非單純的發送數據，而是包括「收集 + 發送 數據」。

而後後面一列info顯示的是具體信息，是查詢用來生成主鍵ID的函數，以前速度都很快，爲啥忽然就這麼慢呢，因而回過頭去查看該函數：

select next_value into ret_val from `xxx` where table_name=tableName for update;

update `xxx` set
		current_value=current_value+step,
		next_value=next_value+step
	where table_name=tableName;
複製代碼

select for update，給這個表加了排它鎖，阻止其它事務取得相同數據集的共享讀鎖和排他寫鎖，同時，這個序列表表中，用來檢索的字段沒有加索引，在InnoDB行鎖機制中：

因爲MySQL的行鎖是針對索引加的鎖，不是針對記錄加的鎖，因此雖然是訪問不一樣行的記錄，可是若是是使用相同的索引鍵（在咱們的場景中，就是查詢時用到的table_name)，是會出現鎖衝突的

因此祥哥瞭解到其它團隊由於查詢這個表產生事務問題，形成死鎖，這個序列表被鎖住了。

因爲這個自增序列表每一個團隊都在使用，因此當時測試環境中，常常有dao層超時錯誤，最終祥哥將這些阻塞的線程kill掉，爲序列表加了索引，解決了問題。

---

小結

下次遇到MySQL執行耗時的狀況，排除了代碼問題以後，要去看數據庫是否有死鎖的狀況存在，觀察有沒有被阻塞的線程，排查被阻塞的線程具體info，定位到具體問題。

---

歡迎吐槽

具體排查過程是這樣，其中還有些細節問題，不清除本身寫的思路或者方法有沒有錯誤，若有請輕噴。

對於MySQL鎖的機制和底層設計，仍是太年輕了，聽祥哥意見，去查看官方文檔，還有多敲一些命令熟悉一下吧。

---

我的博客項目地址

但願各位幫忙點個star，給我加個小星星✨

---

參考資料

1. mysql 卡死 大部分線程長時間處於sending data的狀態

2. 使用Druid監控SQL執行狀態

3. Java JMC監控遠程tomcat配置

4. mysql什麼狀況下會觸發表鎖