最近在工作中經(jīng)常和性能壓測(cè)工作打交道，積累了一些性能分析經(jīng)驗(yàn)，我覺得這些經(jīng)驗(yàn)對(duì)每一個(gè)開發(fā)者都有幫助的，能開發(fā)出性能高的代碼也是我們的最終目標(biāo)。

由易到難，我們逐步介紹不同命令的用法和好處，這些命令是如何幫助我們開發(fā)人員進(jìn)行性能分析的。

一、開發(fā)者的自測(cè)利器-Hprof命令

1、示例演示

例子程序：

/**
 * PROJECT_NAME: test
 * DATE:         16/7/22
 * CREATE BY:    chao.cheng
 **/
public class HProfTest {
    public void slowMethod() {
        try {
            Thread.sleep(1000);
        } catch (Exception e) {
            e.printStackTrace();
        }
    }

    public void slowerMethod() {
        try {
            Thread.sleep(10000);
        } catch (Exception e) {
            e.printStackTrace();
        }
    }

    public static void main(String[] args) {
        HProfTest test = new HProfTest();
        test.slowerMethod();
        test.slowMethod();
    }
}

注：這是一段測(cè)試代碼通過sleep方法進(jìn)行延時(shí)，在程序運(yùn)行過程中很慢，我想知道到底是哪段程序影響的整體性能呢？

我在這個(gè)java程序中，加了如下運(yùn)行參數(shù)：

-agentlib:hprof=cpu=times,interval=10
/* 
    times：java函數(shù)的執(zhí)行時(shí)間
    hprof=cpu是針對(duì)cpu統(tǒng)計(jì)時(shí)間
    interval=10 采樣10次 
*/

再次運(yùn)行這段程序顯示如下圖：

Paste_Image.png

這時(shí)候還發(fā)現(xiàn)在工程目錄里面，多了一個(gè)文本文件java.hprof.txt，如下圖所示：

Paste_Image.png

內(nèi)容如下：

CPU TIME (ms) BEGIN (total = 11542) Fri Jul 22 11:00:34 2016
rank   self  accum   count trace method
   1 86.65% 86.65%       1 303422 com.test.HProfTest.slowerMethod
   2  8.66% 95.31%       1 303423 com.test.HProfTest.slowMethod
   3  0.25% 95.56%      36 300745 java.util.zip.ZipFile.<init>
   4  0.20% 95.76%      36 300434 java.lang.String.equals
   5  0.13% 95.89%      14 301138 java.net.URLStreamHandler.parseURL
   6  0.11% 96.01%       6 301339 java.net.URLClassLoader$1.run
   7  0.10% 96.10%      14 301124 java.lang.String.<init>
   8  0.09% 96.19%    3407 300355 java.lang.String.charAt
   9  0.08% 96.27%      36 300443 java.io.UnixFileSystem.normalize

注：通過上面內(nèi)容可以看到，哪個(gè)類的方法執(zhí)行時(shí)間長(zhǎng)，耗費(fèi)了cpu時(shí)間，一目了然，方便我們快速定位問題。

2、命令的具體講解
hprof不是獨(dú)立的監(jiān)控工具，它只是一個(gè)java agent工具，它可以用在監(jiān)控Java應(yīng)用程序在運(yùn)行時(shí)的CPU信息和堆內(nèi)容，使用java -agentlib:hprof=help命令可以查看hprof的使用文檔。

Paste_Image.png

通過上圖可以看到這個(gè)工具非常強(qiáng)大，可以統(tǒng)計(jì)的東西很多，上面的例子統(tǒng)計(jì)的是cpu時(shí)間，同樣我們還可以統(tǒng)計(jì)內(nèi)存占用的dump信息。
如：-agentlib:hprof=heap,format=b,file=/test.hprof

這個(gè)hprof小工具，非常方便我們?cè)谟肑Unit自測(cè)代碼的時(shí)候結(jié)合使用，既可以解決業(yè)務(wù)上的BUG，又能夠在一定程序上解決可發(fā)現(xiàn)的性能問題，非常實(shí)用。

二、性能排查工具-pidstat

1、示例演示
例子程序：

/**
 * PROJECT_NAME: test
 * DATE:         16/7/22
 * CREATE BY:    chao.cheng
 **/
public class PidstatTest {
    public static class PidstatTask implements  Runnable {
        public void run() {
            while(true) {
                double value = Math.random() * Math.random();
            }
        }
    }

    public static class LazyTask implements Runnable {
        public void run() {
            try {
                while (true) {
                    Thread.sleep(1000);
                }
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    }

    public static void main(String[] args) {
        new Thread(new PidstatTask()).start();
        new Thread(new LazyTask()).start();
        new Thread(new LazyTask()).start();
    }
}

注：這是一段測(cè)試用的java程序，將其運(yùn)行起來。

在命令行輸入：

pidstat -p 843 1 3 -u -t
/* 
-u：代表對(duì)cpu使用率的監(jiān)控
參數(shù)1 3：表示每秒采樣一次，一共三次
-t：將監(jiān)控級(jí)別細(xì)化到線程 
*/

運(yùn)行命令顯示如下圖所示：

Paste_Image.png

再輸入如下命令：

jstack -l 843 > /tmp/testlog.txt

查看testlog.txt顯示如下部分內(nèi)容：

Paste_Image.png

"Thread-0" prio=10 tid=0x00007f7d90103800 nid=0x357 runnable [0x00007f7d943d5000]
   java.lang.Thread.State: RUNNABLE
    at PidstatTest$PidstatTask.run(PidstatTest.java:13)
    at java.lang.Thread.run(Thread.java:722)

   Locked ownable synchronizers:
    - None

以此可以推斷出有性能瓶頸的程序點(diǎn)。

2、pidstat具體命令詳解
pidstat是一個(gè)功能非常強(qiáng)大的性能監(jiān)測(cè)工具，他是Sysstat的組件之一，可以從http://sebastien.godard.pagesperso-orange.fr/download.html 進(jìn)行下載，下載后可以通過./configure等命令進(jìn)行安裝，這個(gè)命令的強(qiáng)大之處在于不僅可以監(jiān)控進(jìn)程的性能情況，也可以監(jiān)控線程的性能情況。

pidstat監(jiān)控cpu常用顯示字段內(nèi)容如下：

1、PID - 被監(jiān)控的任務(wù)的進(jìn)程號(hào)
2、%usr - 當(dāng)在用戶層執(zhí)行（應(yīng)用程序）時(shí)這個(gè)任務(wù)的cpu使用率，和 nice 優(yōu)先級(jí)無關(guān)。注意這個(gè)字段計(jì)算的cpu時(shí)間不包括在虛擬處理器中花去的時(shí)間。
3、%system - 這個(gè)任務(wù)在系統(tǒng)層使用時(shí)的cpu使用率。
4、%guest - 任務(wù)花費(fèi)在虛擬機(jī)上的cpu使用率（運(yùn)行在虛擬處理器）。
5、%CPU - 任務(wù)總的cpu使用率。在SMP環(huán)境（多處理器）中，如果在命令行中輸入-I參數(shù)的話，cpu使用率會(huì)除以你的cpu數(shù)量。
6、CPU - 正在運(yùn)行這個(gè)任務(wù)的處理器編號(hào)。
7、Command - 這個(gè)任務(wù)的命令名稱。

pidstat監(jiān)控io常用的字段顯示內(nèi)容如下：

1、kB_rd/s - 任務(wù)從硬盤上的讀取速度（kb）
2、kB_wr/s - 任務(wù)向硬盤中的寫入速度（kb）
3、kB_ccwr/s - 任務(wù)寫入磁盤被取消的速率（kb）

三、一個(gè)內(nèi)存溢出案例分析

1、內(nèi)存溢出現(xiàn)象
系統(tǒng)共有8臺(tái)服務(wù)器，每次隨機(jī)只有一臺(tái)服務(wù)器報(bào)java.lang.OutOfMemoryError: GC overhead limit exceeded錯(cuò)誤，然后接著就報(bào)內(nèi)存溢出錯(cuò)誤java.lang.OutOfMemoryError: Java heap space。

2、理論支撐
我們先解釋一下什么是GC overhead limit exceeded錯(cuò)誤。

GC overhead limt exceed檢查是Hotspot VM 1.6定義的一個(gè)策略，通過統(tǒng)計(jì)GC時(shí)間來預(yù)測(cè)是否要OOM了，提前拋出異常，防止OOM發(fā)生。Sun 官方對(duì)此的定義是：“并行/并發(fā)回收器在GC回收時(shí)間過長(zhǎng)時(shí)會(huì)拋出OutOfMemroyError。過長(zhǎng)的定義是，超過98%的時(shí)間用來做GC并且回收了不到2%的堆內(nèi)存。用來避免內(nèi)存過小造成應(yīng)用不能正常工作。

可以看到當(dāng)堆中的對(duì)象無法被收回的時(shí)候，就提前遇警報(bào)出這樣的錯(cuò)誤，此時(shí)內(nèi)存并沒有溢出，這個(gè)特性在JDK中是默認(rèn)添加的。

3、DUMP文件分析
將dump文件導(dǎo)入VisualVM工具中，如下圖所示：

Paste_Image.png

通過上圖可以看出類結(jié)構(gòu)圖中，最占用內(nèi)存的是char[]，LinkedHashMap和String三項(xiàng)。但是這三項(xiàng)的實(shí)例數(shù)并沒有占滿，看樣子不會(huì)內(nèi)存溢出，怎么才能具體分析呢？原因就在于GC overhead limt exceed，這個(gè)錯(cuò)并不會(huì)在內(nèi)存真正溢出才會(huì)報(bào)，所以通過dump文件，我們只能自己去判斷分析，哪些項(xiàng)有可能會(huì)造成溢出，我們進(jìn)入char[]項(xiàng)具體來看，會(huì)發(fā)現(xiàn)里面有很多hessian的url字符被緩存，通過排除程序可以看到由于底層中間件程序?yàn)榱颂岣摺靶阅堋?，將每次調(diào)用的url都緩存起來，不用每次都生成，但沒有相應(yīng)緩存釋放操作，于是造成了大量字符對(duì)象長(zhǎng)期持有從而報(bào)錯(cuò)，在此就不截圖來具體看代碼，涉及一些公司信息。

4、問題解決方案

• 可以添加JVM的啟動(dòng)參數(shù)來去掉提前報(bào)警限制：-XX:-UseGCOverheadLimit，于其讓應(yīng)用每次都提前報(bào)警，還不如讓暴風(fēng)雨來的更猛些，直接內(nèi)存溢出，因?yàn)榉?wù)器是集群，其中一臺(tái)掛掉不會(huì)影響線上正常交易，同時(shí)也方便我們通過日志來排錯(cuò)。

• 通過排查程序，檢查系統(tǒng)是否有使用大內(nèi)存的代碼不釋放或死循環(huán)。