壓力測試過程中MySQL服務CPU占用率過高的問題排查思路
- 在關註業務接口的TPS時，也要關註數據庫服務器的QPS。如果一個業務流程裏包含多條查詢，那麽業務接口TPS的上升對數據庫服務器QPS的放大效應會很明顯。
- 如果查詢結果集不大，盡量使用一條查詢語句，通過子查詢返回多個結果集，避免將多個結果集拆分成多次數據庫查詢，否則會造成過多的數據庫連接/查詢操作，消耗IO資源，降低TPS，提高CPU占用率。
- 在業務代碼中，盡量避免在循環語句裏寫數據庫查詢。
- 依據SQL語句的使用頻率來建立索引，查詢條件字段順序按照聯合索引的字段順序來寫（從左到右的匹配順序）
- 關註慢查日誌
一、背景說明
接著上一篇Grpc性能調優的文章繼續寫，我們這次壓測的是一個查詢用戶群組列表信息的接口，該接口裏需要查詢某個用戶的所有群組信息，包括每個群組的名稱、成員數量等。
二、測試過程
數據準備：
-
t_info_group群組表：
- t_info_group_member群組成員表：
數據約定：測試數據中，每個群組裏面有3000個成員；每個成員有20個群組。
1、第一次壓測
我們首先進行一次摸底測試，使用兩臺壓測機器共同發起300個並發，持續壓測2分鐘。（如果只用一臺壓測機發起300個並發，會由於機器端口受限，TPS超過5W後不能發起新請求，壓測機將報錯）
c3p0.initialPoolSize=15
c3p0.minPoolSize=15
c3p0.acquireIncrement=10
c3p0.maxPoolSize=32
（2）數據庫慢查日誌、數據庫服務器監控指標
top命令顯示CPU使用率超過了91%，而且慢查日誌一直在刷！
通過分析慢查日誌裏面的SQL語句，以及對應的數據庫表，發現查詢語句中有“where a=.. and b=.. and c=..”，但是有一個聯合索引的字段是“a, c"。根據聯合索引的匹配規則，這條sql用不了索引，導致慢查。經過將索引更換成"a, b, c"，單條sql查詢效率提高一倍。
2、第二次壓測
使用兩臺壓測機器共同發起50個並發，持續壓測2分鐘。
（1）其他配置均不做改變。
（2）數據庫慢查日誌、數據庫服務器監控指標
經過上述調整，慢查日誌沒有了，但是CPU使用率依然還是超過了90%。這是一個不能容忍的數據，如果並發繼續提高，數據庫服務器很快將被撐爆。
由於其他涉及到sql查詢的接口在壓測時都沒有出現過CPU占用率這麽高的情況，所以我們排除了數據庫服務器安裝配置的問題。
我們開始思考出現問題的可能原因：
- 數據庫連接池等參數配置有缺陷，導致連接池不夠用，一直在建立新的連接。
- 業務代碼邏輯可能存在缺陷，導致查詢語句消耗過多IO或內存資源。
- 並發數量高，數據庫服務器CPU正常就需要占用這麽多。（這是最無奈最不想接受的結局）
我們先查看show processlist; 的結果，發現有很多連接其實是空閑的，也就是說目前的連接池已經夠用了。
而當我們把連接池嘗試放大，配置改為：
c3p0.initialPoolSize=20
c3p0.minPoolSize=20
c3p0.acquireIncrement=20
c3p0.maxPoolSize=128
在這個配置下，對CPU的占用率沒有絲毫影響。那麽排除連接池配置的問題。
那有沒有可能是在當前並發量條件下，就需要消耗這麽多的CPU呢？
我們對比了另一個涉及到SQL查詢的接口，在60個並發下，那個接口的TPS達到了1100，而現在壓測的接口，TPS只有600。那麽在同等並發下，相同的查詢語句復雜度和查詢結果數據量條件下，現在壓測的接口不僅TPS低，還占用了過多的CPU，可能就不是數據庫的問題。這就排除了因並發量高而必然導致CPU占用率超過90%的假設。
我們繼續看數據庫服務器的監控指標，使用阿裏的orzdba腳本監控MySQL服務器。
當前壓測接口的MySQL服務器指標數據：
對照接口的指標數據：
從上述兩個對比圖可以看到，當前壓測接口的數據庫QPS高達3000。對比數據匯總一下，可以看出一些問題：
當前接口：
並發：60，TPS：600，數據庫CPU：92%，數據庫QPS：3000
對照接口：
並發60，TPS：1000，數據庫CPU：20%，數據庫QPS：1400
當前壓測接口處理更耗時，可能原因是一次接口業務裏涉及到了多次數據庫操作。
那麽接下來就是排查業務代碼裏的數據庫操作了。進行code review！
核心業務偽代碼：
//查詢用戶的群組列表
List<Dto> groupList = groupDao.selectGroups(userId);
for(Dto dto:groupList){
//查詢每個群組的用戶數，會循環20次！
int userNumber = groupDao.getGroupNumber(dto.getAsIong(groupId));
}
這段代碼怎麽這麽別扭？第一個查詢已經去查詢群組信息了，還要用for循環去遍歷20次統計每個群組用戶數？？
這樣操作的話，一次接口請求將操作很多次的數據庫查詢，並帶來更多網絡、IO操作。那麽CPU占用率過高的問題很可能是這個情況導致的。
我們的優化措施是優化groupDao.selectGroups(userId)對應的查詢語句，使用子查詢返回用戶的群組列表和每個群組的用戶數，去掉for循環。
3、第三次壓測
使用兩臺壓測機器共同發起50個並發，持續壓測2分鐘。
（1）其他配置均不做改變。
（2）數據庫慢查日誌、數據庫服務器監控指標
數據庫慢查日誌沒有提示慢查SQL語句，數據庫服務器CPU占用率穩定在80%以下，數據庫QPS提高到了近7000！這個優化效果可以說是非常的明顯了。
4、留給我的疑問
也許有人會問：代碼優化後數據庫的QPS比之前更高了，那CPU使用應該更多啊，但是為什麽數據庫的CPU占用率反而降下來了呢？這是為什麽呢？這個問題，其實我也沒有想明白，有知道原因的朋友歡迎留言討論。
-
接口優化前：
並發：60，TPS：600，數據庫CPU：92%，數據庫QPS：3000
- 接口優化後：
並發：60，TPS：1100，數據庫CPU：低於80%，數據庫QPS：6000
壓力測試過程中MySQL服務CPU占用率過高的問題排查思路