1. 程式人生 > 程式設計 >雙十一壓測&Java應用效能問題排查總結

雙十一壓測&Java應用效能問題排查總結

連續參加了兩年公司的雙十一大促壓測專案,遇到了很多問題,也成長了很多,於是在這裡對大促壓測做一份總結。以及記錄一下大促壓測過程中出現的一些常見的Java應用效能問題。

一、為什麼要壓測

  1. 找出應用的效能瓶頸
  2. 探究應用的效能基準
  3. 給大促機器擴容提供參考依據

二、如何壓測

關注哪些指標

吞吐率 TPS(每秒響應的請求數量)

響應時長 RT (一般情況下重點關注90%請求的響應時長,我們的大促標準一般是1s以內)

錯誤率 (看業務的可接受程度,我們的大促標準是不超過2%)

壓測工具

現在有很多可以用來進行壓測的工具,例如ab、jmeter、wrk等,此處主要介紹一下ab和jmeter。

1. ab

ab是一個命令列工具,使用起來非常簡單,

# -c表示併發數,-n表示請求總數,其他一些引數可以查詢手冊/相關資料
ab -c 10 -n 200 https://www.baidu.com/
複製程式碼

命令執行完成後會得出一份壓測結果報告,其中錯誤請求數、TPS和RT在下圖中有標註

image-20191105160037216

2. jmeter

jmeter同時支援圖形化介面和命令列方式,

圖形化方式

首先在"Test Plan"中新增一個"執行緒組",裡面可以設定併發數、壓測時長等引數。

接下來需要在“執行緒組”中新增“HTTP請求取樣器”,裡面是設定HTTP請求的各項引數。

最後新增檢視結果用的監聽元件,我個人比較常用的有“檢視結果樹”、“聚合報告”和“TPS曲線圖”(需要安裝)。

image-20191105163923823

重點來看一下“聚合報告”,(一定要記得每次壓測前都要清理一下資料才行[上方的"齒輪+2個掃把"圖示],不然回合之前的資料混合在一起)

image-20191105165259837

上面只是一些簡單的介紹,事實上jmeter還支援很多複雜的壓測場景: jdbc壓測、dubbo壓測、動態引數壓測、自定義響應斷言……這些可以自行網上搜索。

命令列方式

命令列方式主要可以用來做一些自動化壓測的任務。使用方式如下:

jmeter -n -t [jmx指令碼] -l [壓測請求結果檔案] -e -o [壓測報告資料夾(會生成一堆網頁檔案)]
複製程式碼

其中jmx指令碼可以先通過jmeter圖形化介面全部設定好了,然後儲存一下就會生成對應的jmx指令碼了。

3. ab與jmeter的對比

ab jmeter
操作難度 簡單 複雜
命令列 支援,操作簡單 支援,操作稍微複雜一些
請求結果列表 無法顯示 有詳細請求列表
動態引數 不支援 支援
複雜場景支援 極其有限 豐富

基本上,對於一些簡單的固定引數請求並且是自測的情況下,使用ab會非常簡便。一般情況下jmeter的適用性會更廣。

三、如何制定大促壓測目標

壓測介面的選取

一般情況下,不必要將公司所有的介面都進行壓測,壓測介面主要包含核心鏈路介面、訪問量大的介面以及新上線的活動介面。獲取方式基本是如下兩種:

  1. 對核心業務進行抓包
  2. 諮詢各業務線負責人

壓測併發數的設定

在上面的兩種壓測工具中,我們都看到了一個引數為併發數,這個引數一般需要根據公司的業務量來進行推算,可以去網上找些資料。不過為了簡化壓測過程,我們公司的大促統一使用讀介面200併發,寫介面100併發的標準來執行的。

事實上,我對併發數的設定這塊也比較模糊,因此上述描述僅做參考。

TPS的設定

一般是根據大促銷售目標、平時各介面qps、各介面訪問量按照比例制定出最終的TPS目標,不要忘了最後乘上一個風險係數。具體的演演算法可以自行設計,大概思路就是這樣的。

四、關注哪些指標

對於壓測工具的指標上面已經說過了,主要是關注TPS、RT和錯誤率。

那麼還有哪些需要關注的指標呢?其實這個都是根據公司的業務來決定的,例如我們公司主要使用java應用、mysql作為資料庫、redis作為快取中介軟體,那麼我們主要關注的效能資料如下:

監控物件 效能指標
應用伺服器(服務化應用包含下游鏈路的應用伺服器) CPU、網路頻寬、磁碟IO、GC
資料庫 CPU、網路頻寬、慢SQL
REDIS 網路頻寬

每個監控物件都有其特性,所以應該根據實際情況的來制定自己的監控指標。

五、如何去排查問題

由於公司主要使用的是Java8,因此本文也主要是針對Java8應用做分析。

為什麼要找瓶頸點

舉個例子,如果告訴你一個介面稍微一些壓力就能把伺服器的cpu跑滿了,導致TPS上不去,裡面一堆複雜邏輯,而且還有不少遠端呼叫(資料庫查詢、快取查詢、dubbo呼叫等)。

你可能對業務非常熟悉,開始大刀闊斧地進行程式碼修改、增加快取、業務降級等,也許期望很美好,但是事實上有極大的可能是你做的一切對TPS只能產生輕微的影響。然後只能通過不停地嘗試刪改程式碼去查詢問題點,那麼顯然只能帶來幾個結果: 1.效率低下 2.把程式碼弄的一團糟 3.不具備可複製性 4.對業務會造成或小或大的影響,最最關鍵的是改的時候心裡也沒底、改完之後心裡依舊沒底。

幾個問題(請根據自己的實際認知回答)

  1. 你認為cpu達到100%是好是壞?
  2. 你認為哪些程式碼對cpu的開銷大?你認為大量判斷邏輯對cpu的開銷大嗎?
  3. 你認為大量的網路資料傳輸對哪些指標的影響大?
  4. 你認為對於Java應用監控伺服器記憶體的必要性有多高?

如何排查效能問題

那麼問題來了,我們到底應該怎麼去排查問題呢?(以下均為一些個人經驗,可能會有不少遺漏,或者會有一些錯誤,如果有的話,請及時指出)

排查問題的話,首先我們需要先有一些排查的突破點和方向。(無法保證100%找到對應問題,但是大幅提升找到效能問題的效率)

前面有提到,我們壓測過程中需要監控各項指標,那麼其實我們的突破方向一般就在這些監控指標上了。我們可以對這些指標進行分類,對於每一類都可以有著相對應的排查策略。

1. 資料庫慢SQL問題

這個問題是最好排查的一類問題了,只需要對慢SQL進行鍼對性地分析優化即可,此處不過多講解。

2. 網路頻寬過大

那麼一個問題來了,此處的網路頻寬到底是指的什麼呢?換個問法吧,假設資料庫的頻寬上限為1Gbps,實際上壓測導致資料庫的網路頻寬佔用了800Mbps,那可以說明這個介面是一個問題介面嗎?

考慮下面這種情況,這個介面的TPS假設在壓測過程中達到了80000,遠大於介面實際目標TPS,那該介面將資料庫的頻寬佔到800Mbps是合情合理的。

那麼上面的問題的答案也就呼之欲出了,這裡的網路頻寬,在很多情況下,我們更應該關注的是單個請求的平均佔用頻寬。

如何排查網路頻寬過大的問題

猜一猜,其實不難想象,就是抓包。我常用的抓包方式是通過tcpdump抓包,然後使用wireshark解析抓包內容(如果有更簡單的方式,可以留言)。下面講一下tcpdump+wireshark的方式如何抓包。

為了避免大量的資料混雜在一起,一般情況下,我更喜歡是抓單個請求的資料,而不是在壓測中抓包。下面簡單介紹一下tcpdump和wireshark如何抓包,

  1. 在伺服器上執行命令sudo tcpdump -w xxx.pcap
  2. 然後請求一下介面
  3. Ctrl+C停掉tcpdump
  4. 將xxx.pcap拷到本地,使用wireshark開啟
  5. 如下圖,找到一個請求 > 右鍵"Follow" > "TCP Stream"

image-20191106175128011

開啟TCP流後通過調整右下方的"Stream",我們就可以看到應用在請求過程中的網路資料(包含Http請求資料、Mysql請求資料、Redis請求資料……),以下圖為例,可以看到這個請求的mysql請求量非常大,接下來就是檢視到底是哪些SQL語句導致的。

image-20191106175708652

3. 資料庫CPU過高

開啟資料庫日誌,看看壓測期間都執行了哪些SQL語句,然後進行鍼對性的分析即可。一般情況下,全表掃描、不加索引、大表的count這些都比較容易引起cpu問題。絕大多數情況下都可以通過技術手段來優化,但也有可能技術手段無法優化的情況,則可以考慮業務上的優化。

4. 應用伺服器磁碟IO問題

絕大多數情況下是由於日誌問題導致的,日誌問題一般分為如下兩種情況:

  1. 壓測介面引數/環境有問題,導致介面不停地列印異常
  2. 列印了大量的業務日誌

至於其他的磁碟IO問題,則需要根據實際業務去分析了,暫時未遇到過,此處略過。

5. GC問題

一般情況下,我們不太需要去關注YoungGC,更多地只需要關注FullGC就行了,如果只是偶爾出現一次FullGC,那基本上沒有太大問題,如果頻繁FullGC(幾秒就有一次FullGC,甚至可能一秒幾次),那就要做相應排查了。

如何監測FullGC

一般可以通過jstat來監測,命令如下:

jstat -gccause [PID] 1000
複製程式碼

image-20191106141050865

具體的每個引數的含義可以檢視man jstat手冊。

其實用visualvm裝個GC外掛然後監測java程式,可以很直觀地看到java應用的記憶體和GC情況,就是操作相對而言比較繁瑣。

如何排查GC問題

很多情況下(主要是大物件/大量堆物件導致FullGC的情況),都可以通過將Java堆dump下來,然後通過MAT、jhat等記憶體分析工具來分析。流程如下:

  1. 首先需要dump堆檔案,在伺服器上執行如下命令: jmap -dump:format=b,file=heap.bin [PID]
  2. 然後將堆檔案拷到本地,使用MAT開啟(需要調大記憶體啟動引數,必須要比堆檔案大),個人比較常用的MAT功能是"Leak Suspects"和"Histogram",前者是可能出現記憶體洩漏的懷疑點,後者是堆中類的直方圖
舉個例子

此處以一個真實的出現過宕機的Java應用的堆作為舉例(加上-XX:+HeapDumpOnOutOfMemoryError這個引數就可以在出現OOM的時候自動將堆dump下來了)

image-20191106144338830

本文簡單看一下"Leak Suspects",至於Histogram則可以自行去研究。

image-20191106145139680

這個堆檔案其實還是比較簡單的,因為可懷疑點只有一個,八九不離十就是這塊出現問題了。點選"Details"可以看到更詳細的資訊(ps:不是每種懷疑物件都有Details的)。

image-20191106145600510

在詳細資訊裡面基本上可以很明顯地看出來,有一個SQL語句查出來了超多的資料,導致記憶體塞不下了。事實上,最終在資料庫日誌中找到了這條語句,共查詢了200W+條資料。

這個例子比較簡單,事實上我們可能會遇到更多複雜的情況,例如懷疑物件特別多,甚至真正原因並不在懷疑物件中,或者metaspace導致的FullGC,這些情況下,我們可能又需要採用其他方式去處理這些問題。

6. 應用伺服器cpu達到100%問題(以下只針對常規業務應用,不考慮追求極端效能應用)

還記得之前的有個問題——你認為cpu達到100%是好是壞嗎?

那麼在這裡我揭曉一下答案,如果介面的TPS高,那麼我們的伺服器的cpu當然是越高越好了,因為這說明瞭資源被充分利用了。但是,如果介面的TPS低,那麼cpu達到100%就說明很有可能是有問題了,很大可能是存在問題程式碼佔據了大量的cpu。

那麼還有一個問題就是,你認為哪些程式碼對cpu的開銷大?

  1. 大量的業務邏輯判斷——幾乎無影響 (上萬個if語句可能總的執行時間都不會超過1ms)
  2. 大量的網路傳輸——幾乎無影響 (會有一些cpu開銷,但是極其有限,可以找個應用生成火焰圖看看)
  3. 執行緒阻塞——幾乎無影響 (如果不考慮極其大量的執行緒切換的話,那麼執行緒阻塞是不會佔用cpu的)
  4. 大量的記憶體拷貝——幾乎無影響 (會有一些cpu開銷,但是極其有限,可以找個應用生成火焰圖看看)

這些都沒有影響,那到底什麼才對cpu有影響呢?常見的業務場景總結如下(如有遺漏請留言補充)

  1. 長度特別大的迴圈,尤其是多層巢狀迴圈
  2. 字串處理,常見的消耗cpu的操作是json解析、正則表示式
  3. 日期格式化,Date.format非常消耗cpu
  4. 大量的sql資料處理,sql資料處理量很多的情況下是會大量佔用cpu的,這個情況最為常見
  5. 大量的日誌輸出有時也會佔用不少的cpu,不過更多的情況是產生執行緒阻塞

排查cpu問題的方式

我在大促壓測中實踐的比較多的方式是perf + perf-map-agent + FlamaGraph工具組合,其中perf是用來監控各個函式的cpu消耗(可以實時監控,也可以記錄一段時間的資料),perf-map-agent是用來輔助perf使用的,用來生成java堆的對映檔案,FlamaGraph則是用來生成火焰圖的。

這套工具的安裝使用就不做介紹了,可以參考一下下面這兩篇文章,

senlinzhan.github.io/2018/03/18/… www.jianshu.com/p/bea2b6a1e…

主要使用方式,有如下兩種:

  1. sudo perf top [-g],可以實時觀察cpu的消耗,操作相對比較輕量級
  2. 生成火焰圖(一定要用瀏覽器開啟),操作相當繁瑣,不過生成的資訊也更詳細,更易閱讀,對於那些無法一眼看出來的問題會有不錯的效果

火焰圖示例

下面展示一下本次大促壓測solr優化過程中生成的火焰圖,從圖中可以看到YoungGC就佔用了將近一半的cpu,

image-20191106155941396

perf-top示例

用這個示例程式碼做個perf-top的使用示範:

import java.text.SimpleDateFormat;
import java.util.Date;

public class Cpu {

    private static final int LIMIT = 100000000;

    public static void main(String[] args) {
        simple();
    }

    private static void simple() {
        int count = 0;
        long startTime = System.currentTimeMillis();
        while (count < LIMIT) {
            Date date = new Date();
            SimpleDateFormat df = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss SSS");
            String sd = df.format(date);
            if (sd.length() == 23) {
                count++;
            }
        }
        System.out.println(System.currentTimeMillis() - startTime);
    }
}
複製程式碼

首先使用perf-map-agent/bin/create-java-perf-map.sh [PID]生成JVM對映檔案,然後使用sudo perf top可以看到cpu基本上都被SimpleDateFormat給佔用了,(下面還有很多展示不出來的,事實上會更多)

image-20191107113205727

有了這些工具之後,絕大多數問題都已經可以比較容易地找到效能優化點了。

其他一些方式

上面那套組合實際用起來十分繁瑣,大促壓測結束後又瞭解到了一些其他工具,不過未經過真實實踐,所以列出來僅做參考:

  1. jvmtop
  2. github.com/oldratlee/u… ,這個裡面有個show-busy-java-threads指令碼,試用了一下,感覺超方便,後續考慮在真實排查問題中實踐一下

7. 執行緒阻塞問題

當我們在系統的所有環節都無法找到硬體瓶頸的時候,那往往就是執行緒產生了阻塞,一般情況下執行緒阻塞可以使用jstack和arthas來排查,分別舉個例子吧,用下面這段樣例程式碼:

public class Main {

    public static void main(String[] args) {
        for (int i = 0; i < 30; i++) {
            new Thread(() -> {
                while (true) {
                    run();
                }
            },"myThread-" + i);
        }
    }

    private static void run() {
        Integer x = 1;
        for (int i = 0; i < 100000; i++) {
            x *= i;
        }
        System.out.println(x);
        sleep(10);
    }

    private static void sleep(long millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}
複製程式碼

jstack的方式檢視

jstack [PID]
複製程式碼

image-20191106184616989

從圖中可以看到大量的執行緒都卡在Block.sleep()上。一般情況下,jstack可以配合grep來使用,通常關注得比較多的狀態更多是BLOCKED。jstack相對而言沒那麼直觀,但是比較輕量級,很多時候也可以比較容易地看出來一些常見的執行緒阻塞問題。

arthas的方式檢視

arthas其實是一個比較全能的jvm效能分析工具,用起來也是各種舒服,而且相對而言也比較輕量,強烈推薦。

此處主要介紹arthas在排查執行緒阻塞方面的應用,

  1. 執行arthas,命令java -jar arthas-boot.jar
  2. 選擇目標java程式
  3. 執行trace [包名.類名] [方法名] -n [數量] '#cost>[執行時間]'就可以查看了,更多引數可以查詢arthas的檔案

image-20191106185440691

如上圖,我們可以看到各個方法的執行時間(包含了阻塞時間),篩選出執行時間長的方法,很大可能就能發現造成執行緒阻塞的瓶頸點。

8. 記憶體洩漏問題

記憶體洩漏問題往往都伴隨著宕機,我所遇見的情況有如下幾種:

Heap記憶體洩漏

這種情況屬於相對而言比較容易處理的情況,使用-XX:+HeapDumpOnOutOfMemoryError引數可以在應用宕機的時候自動dump下堆檔案,然後使用MAT等記憶體分析工具在絕大多數情況下都可以找到問題原因。

metaspace記憶體洩漏

這個有見過JVM呼叫groovy在某些情況下會產生記憶體洩漏。不過沒有真實排查過相關問題,此處略過。

防風有一篇文章可以參考一下GroovyClassLoader 引發的 FullGC

nonheap記憶體洩漏

nonheap記憶體洩漏問題屬於非常難排查的問題,一般情況下比較難dump下堆檔案,即使dump下來了,一般情況下也很難確定原因,之前有用過tcmalloc、jemalloc等工具進行排查過。暫時沒找到什麼比較通用的套路,一般也是特事特辦。根據之前的排查經驗來看,如下幾種情況會比較容易出現nonheap記憶體洩漏(如果遺漏,請留言補充):

  1. 圖片合成業務中,涉及到Font的建立,可以詳見之前的文章記一次Font導致JVM堆外記憶體洩漏分析
  2. 使用了JNI的情況下很有可能會導致JVM的arena記憶體區剛好超過機器記憶體限制 / nonheap記憶體洩漏(可以參考防風的文章JNI 引發的堆外記憶體洩露
  3. GZIPStream未關閉的情況會導致nonheap洩漏 (來源於網上資料,未真實遇到過)

9. 從業務角度去排查問題

排查很多問題之前,最好能夠先去了解一下相關業務邏輯,因為很多效能問題是由於大量的問題業務程式碼引起的,很多時候從業務角度去考慮、輔以技術手段往往能夠得到更好的效果。

10. 總結

上面的各種方式只是提供一些策略,無法保證100%能夠找到問題,甚至可能連70%都保證不了,更多情況下我們需要靈活使用各種工具進行問題分析。總結一下上面的效能分析工具,可以大概如下分類:

型別 工具
全能型分析工具 arthas、visualvm
cpu分析工具 perf、jvmtop
記憶體分析工具 jmap、jhat、MAT
網路分析工具 tcpdump、wireshark
GC分析工具 jstat、gc日誌檔案、visualvm
堆疊分析工具 jstack、arthas
Linux底層排查工具 strace、perf、dmesg、journalctl

有些工具甚至有更多的功能,例如arthas和visualvm,可能會漏掉一些分類,每種分類也同樣還有著各種各樣其他的分析工具,此處就不求盡善盡美了。

六、壓測中出現的典型效能問題

以下總結一下我在大促壓測過程中所遇到的一些比較典型的效能問題。

1. Log4j日誌阻塞問題

公司的部分老應用仍然使用的Log4j,列印日誌全部為同步方式,就會導致在併發高且業務日誌多的情況下,會造成日誌大量阻塞。

2. redis大value問題

有些程式碼不論有多大的資料都直接往redis裡面塞,只要併發稍微一高,就很容易導致redis的頻寬達到上限。

3. sql全欄位查詢問題

很多程式碼查詢mysql的時候,無論什麼場景都會將表的所有的欄位都查詢出來,會導致兩個結果:

  1. 網路頻寬極大浪費,尤其是查詢中包含了不必要的"描述"等超大欄位
  2. 極大地消耗cpu資源

4. sql未加索引問題

比較容易犯的問題,一般會產生慢SQL,甚至可能導致資料庫cpu消耗嚴重。

5. sql N+1問題

也是比較容器犯的問題,會對應用本身和資料庫都產生或多或少的效能影響,至於具體的影響度暫時還沒有直觀資料。

6. 正則表示式問題

正則表示式在業務中也是比較常用的,但是有些糟糕的正則表示式可能會導致一些可怕的後果,會嚴重消耗cpu資源,舉個例子,如下

public class Regex {

    public static void main(String[] args) {
        String regex = "(\\w+,?)+";
        String val = "abcdefghijklmno,abcdefghijklmno+";
        System.out.println(val.matches(regex));
    }
}
複製程式碼

就這麼一段看上去簡單的程式碼,會一直保持著cpu單核100%的狀態,而且會執行15秒左右。具體原因可以詳見防風的文章 www.ffutop.com/posts/2018-…

7. DateFormat問題

大量使用DateFormat導致極大地cpu資源消耗,一般情況下請使用FastDateFormat替代SimpleDateFormat,效能能提升一倍以上。對於一些時間點比較規整的且瓶頸點仍在DateFormat上的,可以考慮使用快取等方案。

8. 執行緒池不正確使用問題

遠端呼叫時長遠大於cpu消耗的業務直接使用預設執行緒池或著執行緒數設定太少,很容易導致執行緒阻塞。

9. 傳說中的問題

只聽說過,但是我還從未真實見到過,

  1. 大量執行緒切換導致cpu開銷大
  2. 資料庫死鎖問題
  3. 資料庫連線池設定問題(有發生過幾次,但是我都不在現場)
  4. ... ...