記一次接口壓力測試與性能調(diào)優(yōu)

〇、經(jīng)驗(yàn)總結(jié)

1.如果總的CPU占用率偏高，且基本都被業(yè)務(wù)線程占用時，CPU占用率過高的原因跟JVM參數(shù)大小沒有直接關(guān)系，而跟具體的業(yè)務(wù)邏輯有關(guān)。
2.當(dāng)設(shè)置JVM堆內(nèi)存偏小時，GC頻繁會導(dǎo)致業(yè)務(wù)線程停頓增多，TPS下降，最后CPU占用率也低了；
3.當(dāng)設(shè)置JVM堆內(nèi)存偏大時，GC次數(shù)下降，TPS上升，CPU占用率立刻上升。
4.Dom4J 這個xml解析工具性能很強(qiáng)大，但在處理節(jié)點(diǎn)和層級都較多的xml文本時，整體解析效率依然會成為業(yè)務(wù)處理瓶頸。

一、背景說明

最近新項(xiàng)目上線，需要對項(xiàng)目中的一個HTTP接口進(jìn)行壓力測試，以保證接口性能穩(wěn)定性。該接口涉及到的主要業(yè)務(wù)是接收HTTP請求，獲取請求中的xml報(bào)文參數(shù)，并將xml報(bào)文解析后存入MySQL數(shù)據(jù)庫。接口業(yè)務(wù)流程如下：

該業(yè)務(wù)接口部署的服務(wù)器配置和部署MySQL組件的服務(wù)器配置一致，都是4核8G，50G普通硬盤，并且處于同一個內(nèi)網(wǎng)網(wǎng)段，我們預(yù)估的性能指標(biāo)要達(dá)到200并發(fā)，500TPS。
在壓力測試過程中，我們重點(diǎn)關(guān)注TPS、GC次數(shù)、CPU占用率和接口響應(yīng)時間等指標(biāo)。

二、測試過程

完成項(xiàng)目部署后，我們開始編輯jemeter測試腳本，設(shè)置壓力測試的標(biāo)準(zhǔn)為200個并發(fā)線程，在10秒內(nèi)全部啟動，持續(xù)壓測時間15分鐘，接著開始啟動jemeter腳本進(jìn)行測試。

1、第一次壓力測試

（1）JVM配置

垃圾收集策略包括：老年代啟用CMS垃圾收集算法，新生代啟用ParNew垃圾收集算法，新生代最大存活周期為15次minorGC，F(xiàn)ullGC時使用CMS算法，并開啟CMS中的并行標(biāo)記。
JVM內(nèi)存分配：最大/最小堆內(nèi)存為512MB，Eden和Survivor比例為8:2，永久代初始化64MB，最大128MB。
JVM配置參數(shù)如下：
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:MaxTenuringThreshold=15 -XX:+ExplicitGCInvokesConcurrent
-XX:+CMSParallelRemarkEnabled -Xms512m -Xmx512m -XX:SurvivorRatio=8 -XX:PermSize=64m -XX:MaxPermSize=128m

（2）性能指標(biāo)監(jiān)控

top命令觀察java線程的CPU占用率(us表示用戶進(jìn)程，sy表示系統(tǒng)進(jìn)程)：

jemeter工具輸出的TPS和接口響應(yīng)時間：

jstat -gcutil {pid} {period_time} 輸出GC情況

我們根據(jù)上述指標(biāo)監(jiān)控的情況可以看出，目前CPU占用率很高，每個CPU上的業(yè)務(wù)線程都占用了90%以上的CPU時間，年輕代GC次數(shù)頻繁，平均每秒鐘有8次左右，但TPS目前只有400左右。
一開始看到這個情況，我們以為是JVM堆內(nèi)存分配的不足，導(dǎo)致GC頻繁，從而引起CPU的高占用率。所以我們調(diào)大了堆內(nèi)存參數(shù)，并進(jìn)行第二次壓力測試。

2、第二次壓力測試

（1）JVM配置

JVM內(nèi)存分配：最大/最小堆內(nèi)存為2048MB，Eden和Survivor比例為8:2，永久代初始化512MB，最大512MB。
JVM配置參數(shù)如下：
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:MaxTenuringThreshold=15 -XX:+ExplicitGCInvokesConcurrent
-XX:+CMSParallelRemarkEnabled -Xmx2048m -Xms2048m -Xmn1024m -XX:NewSize=640m -XX:MaxNewSize=640m
-XX:SurvivorRatio=8 -XX:PermSize=512m -XX:MaxPermSize=512m

（2）性能指標(biāo)監(jiān)控

top命令觀察java線程的CPU占用率(us表示用戶進(jìn)程，sy表示系統(tǒng)進(jìn)程)：

jemeter工具輸出的TPS和接口響應(yīng)時間：

jstat -gcutil {pid} {period_time} 輸出GC情況:

根據(jù)上述指標(biāo)監(jiān)控的情況可以看出，這次JVM參數(shù)調(diào)整后，隨著堆內(nèi)存擴(kuò)大，年輕代GC次數(shù)降低了，平均每秒有2次左右，TPS提高到600左右。但是CPU占用率依然很高，且都為業(yè)務(wù)進(jìn)程占用。
從這個性能結(jié)果來看，堆內(nèi)存的增大，可以降低GC頻率，提高TPS。但CPU占用率幾乎沒有變化，可能的原因預(yù)計(jì)有兩個：
第一、業(yè)務(wù)邏輯中存在耗CPU的計(jì)算操作；
第二、業(yè)務(wù)代碼存在鎖，導(dǎo)致大量線程在等待鎖。
根據(jù)這個猜測，我們決定打印出JVM線程快照，看下能否找到線程等待鎖的相關(guān)信息。
jstack -l {pid} > /log_dir/stack_log.txt 命令輸出線程快照信息到指定的目錄文件。
在線程快照文件里查找狀態(tài)為BLOCKED的線程記錄，發(fā)現(xiàn)出現(xiàn)較多BLOCKED狀態(tài)的線程是：

從線程快照來看，大量xml解析線程處于BLOCKED狀態(tài)，xml解析的業(yè)務(wù)處于阻塞狀態(tài)，降低了接口處理效率。

接著我們把接口代碼中其他邏輯代碼屏蔽，只留下xml解析代碼，發(fā)現(xiàn)CPU占用率依然在90%以上，而一旦把xml解析代碼屏蔽，留下其他業(yè)務(wù)代碼，CPU占用率馬上降低到了70%，TPS上升，GC次數(shù)下降并保持穩(wěn)定。

從上面這些處理的結(jié)果來看，CPU占用率過高的原因跟JVM參數(shù)大小沒有直接關(guān)系，而跟xml參數(shù)解析有關(guān)，因?yàn)閤ml參數(shù)報(bào)文包含十幾個節(jié)點(diǎn)，層級也較多，解析后生成的都是比較復(fù)雜的大對象。
當(dāng)設(shè)置JVM堆內(nèi)存偏小時，GC頻繁會導(dǎo)致業(yè)務(wù)線程停頓，TPS下降，最后CPU占用率也低了；
當(dāng)設(shè)置JVM堆內(nèi)存偏大時，GC次數(shù)下降，TPS上升，CPU占用率立刻升高到95%以上。
由于我們對xml參數(shù)解析使用的是dom4j的方法，所以沒辦法在xml解析上面進(jìn)行優(yōu)化，只能在JVM參數(shù)和并發(fā)數(shù)上進(jìn)行處理。
最終為了平衡CPU占用率、TPS、GC三個方面的指標(biāo)，考慮業(yè)務(wù)實(shí)際場景，我們設(shè)置JVM堆內(nèi)存為1.5G，限制TPS為200。