Java應用性能瓶頸分析思路

1 問題描述

　　因產品架構的複雜性，可能會致使性能問題的因素有不少。根據部署架構，大體的能夠分爲應用端瓶頸、數據庫端瓶頸、環境瓶頸三大類。能夠根據瓶頸的不一樣部位，選擇相應的跟蹤工具進行跟蹤分析。

　　應用層面瓶頸大體有以下兩類，一是應用服務端複雜的邏輯處理致使應用端代碼執行慢；二是資源鎖爭用致使線程阻塞問題（最典型的特徵是線程狀態爲「java.lang.Thread.State: BLOCKED (on object monitor)」）等。

　　數據庫層面瓶頸表現出來的現象都是SQL執行慢，其緣由可分爲兩種，一是因索引缺失、SQL不規範等致使的SQL自身性能差；二是由於受環境資源瓶頸或併發資源鎖等影響出現等待致使的SQL執行慢。

　　環境瓶頸致使的影響一般是總體性的，常見的有應用及數據庫服務器的資源瓶頸（CPU、內存、IO等）、網絡瓶頸等。

　　根據業務場景的不一樣特徵，針對單點和併發兩種場景，能夠採用不一樣的方式進行跟蹤分析。在分析單點場景性能問題時，能夠經過相關agent探針追蹤鏈路信息，進而進行進一步分析，複雜場景能夠藉助JProfiler、Arthas、連續屢次抓取線程快照等方式進行跟蹤分析。JProfiler、Arthas兩個工具優勢是能夠直觀方便的進行跟蹤分析，可是性能開銷較大。在併發場景，通常採用屢次抓取線程及數據庫會話快照的方式進行跟蹤分析。

2 故障排查

2.1 總體思路

明確現象，跟蹤數據，尋找瓶頸，優化瓶頸。

　　不管應用仍是數據庫，不管用各類工具分析報告仍是原始的線程堆棧、會話日誌的方式進行跟蹤分析，其思路都是一致的，都是依據跟蹤數據，明確熱點內容，分析性能瓶頸。根據跟蹤的數據分析線程或DB會話狀態、執行的線程堆棧、SQL內容等信息，明確熱點內容，進而定位性能瓶頸。

2.2單點場景性能分析

　　單點場景性能分析，能夠經過集成相關鏈路性能跟蹤探針進行定性分析，相似插件能夠跟蹤請求和SQL信息，能夠直觀的獲得瓶頸內容。有時瓶頸出如今應用服務端，可是因業務邏輯較複雜，一個請求涉及跨多個產品模塊的調用，很難根據程序跟蹤器的日誌快速定位到準確的瓶頸點，這種場景則須要藉助調試工具作進一步分析。在此，重點針對功能較完善的JProfiler工具和全部環境都適應的JDK Jcmd工具進行示例。其餘工具能夠根據我的喜愛，參考幫助文檔使用。

2.2.1 Jprofiler跟蹤方案

　　應用層面單點性能跟蹤的主要目標爲應用方法級耗時分析，可針對方法消耗的CPU資源進行跟蹤。具體方法爲：在開始驗證問題以前，先經過「StartRecording」開啓跟蹤，而後重現問題，操做完成後點擊「StopRecording」便可完成跟蹤。

Start Recording

 

 Stop Recording

 

 跟蹤結束後，選擇CPU views-Call Tree便可查看跟蹤時段的方法級耗時分佈狀況。

注意，因跟蹤過程當中會記錄跟蹤時段JVM全部的信息，爲減小其餘操做對目標場景的影響，通常建議在跟蹤時儘可能減小其餘人員同時操做系統。如沒法避免其餘人員操做帶來的干擾，能夠經過方法名、類名等搜索過濾關鍵信息來快速定位。

 

 

 2.2.2 JDK內部工具跟蹤方案

　　有時可能因用戶管理規範等緣由，項目環境沒法安裝JProfiler等第三方工具，咱們也能夠經過連續抓取線程快照的方式，在驗證問題時進行高頻採樣，統計業務典型堆棧出現的頻數，根據不一樣堆棧內容出現的頻數比例便可大概的明確性能耗時分佈狀況。具體操做方式以下：

跳轉到JDK的bin目錄，執行以下命令開啓連續打印線程快照，開啓線程快照打印以後重現有問題的功能場景，功能執行結束以後，經過Ctrl+C命令終止快照打印，跟蹤結束後在JDK bin目錄下即會產生一個線程快照文件SingleTrace.log。

for i in {1..10000}; do ./jcmd /jstack/runtime/caf-bootstrap.jar Thread.print >> SingleTrace.log ;  done;

最終生成的線程快照文件一般較大，能夠藉助VSCode、notepad++等工具進行統計分析。文件打開以後，第一步能夠先統計每一個線程快照頂部的「Full thread dump OpenJDK 64-Bit Server VM」獲得抓取線程快照的總次數，以後能夠結合業務場景的典型方法進行統計在相關方法出現頻數，根據典型場景佔總次數的比例便可大概的明確對應方法在總耗時中佔用的比例。

 

 2.3 併發場景性能分析

　　在作併發場景性能跟蹤時，爲減少因抓取性能數據對系統總體帶來過大的性能開銷，一般以固定時間間隔（如每次間隔5s）連續屢次抓取快照的方式進行收集性能數據。結合產品的實際狀況，一般須要重點關注應用層面線程狀態和數據庫層面的會話狀態兩類信息。所以，在跟蹤過程當中一般採用應用線程快照+數據庫會話快照相結合的方式進行跟蹤。分析時可用結合問題時段的線程狀態、堆棧信息、數據庫會話狀態狀況定位性能瓶頸。通常來講，線程狀態爲RUNNABLE狀態，在同一份線程快照出現頻率高、或者不一樣快照中出現頻率高的線程通常爲性能瓶頸內容。

2.3.1 應用層跟蹤方案

收集線程堆棧快照的命令：jcmd PID Thread.print >>tracelog.log。

爲了操做方便，整理了批量腳本，按照以下步驟操做便可收集內存及線程信息，在分析線程問題時，只關注線程堆棧相關內容便可。

①  將troubleshooting.sh文件放到JDK的bin目錄下，具體路徑爲*/jstack/runtime/java/x86_64-linux/bin

②將troubleshooting.sh授予可執行權限：chmod +x troubleshooting.sh

③運行troubleshooting.sh抓取堆棧信息：./troubleshooting.sh 。執行後在jdk bin目錄下會產生一個命名爲trace.log的日誌文件，trace.log默認只保存最近一次抓取的日誌內容。

④經過 sz trace.log命令或其餘文件傳輸工具將日誌文件下載到本地查看便可。

 

2.3.2 數據庫會話跟蹤

　　DBSQLMonitor工具（http://gsk.inspur.com/File/t-7237）能夠自動按期記錄數據庫會話信息，工具支持跟蹤全部會話和僅阻塞兩種模式。在大量複雜的DB阻塞場景，僅阻塞模式生成的日誌能夠快速的定位阻塞源；全部會話模式生成的日誌更併發場景分析SQL瓶頸。

　　工具部署。將工具部署於任一能鏈接數據庫的機器，使用具備管理員權限的用戶登陸工具，根據分析場景的須要，將跟蹤方式設置爲全部會話或僅阻塞模式，並設置記錄會話快照的時間間隔。在併發性能分析時，爲可以更準確的記錄真實的環境信息，一般將時間間隔設置爲工具容許的最小時間間隔3s。

 

　　日誌分析。跟蹤結束後，在分析併發場景SQL性能時，能夠直接篩選活動狀態（非sleeping、Inactive）的會話，結合會話狀態、等待事件、會話內容等信息肯定數據庫層面性能狀況。

日誌說明。Idx表示一次會話快照中的日誌編號;logTime爲時間戳，相同時間戳的多條記錄表示在時間戳時刻的多個會話； spid爲sessionID；blocked爲阻塞當前會話的sessionID，該字段內容對應spid，blocked爲0的表示沒有被阻塞；status爲當前會話狀態；lastWaittype爲會話等待事件；programName爲當前鏈接對應的進程名稱，GSCloud對應的進程名爲JDBC Thin Client；sqlText爲當前會話正在執行的SQL腳本。

 

2.3.3 典型場景分析思路

    併發場景性能瓶頸大體能夠分爲以下幾種狀況：

（1）應用自身代碼邏輯執行慢

　　應用層面代碼執行慢的問題，表現到線程跟蹤日誌上就是某個活動狀態的線程在某個方法執行的時間很長。如JProfiler日誌中某方法耗時很長、同一個快照有多個線程在執行相同內容或連續多個線程快照均在執行某方法等。明確瓶頸方法後，分析棧頂或Jprofiler中top耗時的最葉子節點便可。

典型特徵：線程狀態爲RUNNABLE狀態，且棧頂爲非等待類型堆棧。

以下示例中，屢次抓取線程快照，線程狀態一直保持RUNNABLE，產品線程棧頂均爲XXX.readValue()，且棧頂代碼沒有出現等待。所以，咱們能夠得出，XXX.readValue()是因爲String.intern()致使。

 

（2）非應用自身邏輯致使的等待

　　有時還會出現因應用如下層面資源致使的性能瓶頸，如SQL效率低致使應用長時間等待數據庫返回數據、應用與數據庫之間網絡環境不佳致使接收數據庫返回的結果集時耗時過長等。

 

①數據庫SQL執行慢

　　當發現大量活動線程在等待數據庫返回時，則須要進一步結合數據庫session日誌作進一步分析。以以下示例爲例，當前時刻的線程快照中有61個線程在等待網絡返回，此時能夠檢查相關時段活動狀態的會話狀況，假如線程快照先後的數據庫會話中活動會話數與等待網絡返回的數目接近，則基本能夠肯定應用層面的等待是因爲SQL性能差致使。

典型特徵：線程狀態爲RUNNABLE，且棧頂在存在網絡相關等待，且數據庫會話中存在大量活動狀態會話。

②網絡等環境因素致使等待

　　有時還會有另外一種場景，線程快照中存在大量等待網絡返回的活動線程，可是數據庫層面並無與之對應的出現大量活動狀態的會話，這種狀況多是如棧頂代碼所示，應用和數據庫服務器之間真正的出現了網絡瓶頸。

    典型特徵：線程狀態爲RUNNABLE，且棧頂在存在網絡相關等待，且數據庫會話中沒有貨只有個別零散的活動狀態會話（個別是指一次出現的活動會話數不多；零散是指活動會話出現的頻率低，間隔很長時間出現一次）。

    Linux環境還可使用iftop工具進行網絡狀況監控。

（3）應用層面出現併發等待（線程阻塞）

　　在併發場景，有時候會出現由於資源鎖致使的等待問題，線程阻塞問題涉及兩種狀態的內容，一是阻塞源線程，阻塞源線程狀態爲RUNNABLE狀態，此類線程一般是因爲自身或某些外部因素致使的線程執行慢，進而致使申請的資源鎖未能及時釋放；二是被阻塞的線程，此類線程均爲BLOCKED狀態，且等待的多爲同一個資源。

以以下被阻塞的線程爲例，當前線程在執行_addSymbol()方法時，對lock <0x00000004d23c52c0>加鎖失敗致使出現等待，進而該線程處於被阻塞狀態。通常來講，相同方法申請同一個資源的機率相對更大，所以，咱們能夠用等待加鎖的方法做爲關鍵詞，搜索存在相關關鍵詞的非BLOCKED狀態線程大機率即爲阻塞源線程，最終發現該線程阻塞是因爲場景（1）中XXX.readValue()方法的String.intern()致使。

 

典型特徵：線程狀態爲BLOCKED

3 解決方案

根據分析結論，優化瓶頸內容。