java 性能分析工具

本文介紹了常用的性能分析工具和故障排查工具，希望可以幫助開發人員在排查性能問題的時候快速定位到性瓶頸。每個工具都有其優勢與劣勢，只有更好了解問題所出現的場景，理清解決問題的思路，才能最大化的發揮工具的價值。

 

 

 

0. Introduction

Java 性能優化分為很多個方面，如系統優化、算法優化、代碼優化等。代碼優化是指開發人員在研發、測試過程中使用性能瓶頸分析工具快速定位出由於編碼存在的性能瓶頸問題並持續進行優化。一種很常見的場景是測試同學在對服務進行壓測時，無論怎么增加並發應用的 TPS 一直保持在某個值進行左右波動，這個時候要怎么排查呢。為了可以准確獲得運行過程中程序的性能數據，性能調優人員和開發者需要使用性能分析(profiling)輔助工具從全局視角來查看系統的運行狀況。本文主要介紹通過熟練掌握 JMC、Tprofiler、JProfiler 等各種性能瓶頸分析工具，進而提高定位性能瓶頸、系統故障排查能力。

1. Java Mission Control

JMC(Java 任務控制)是 Java 7u40 新增加的性能監控工具。目前，Oracle Java 官方在今年 5 月份已經公布 Java Mission Control(JMC)的源代碼已正式開源，此舉得到了 Java 開發社區的高度贊賞。

JMC 源碼地址： JMC source code

 

 

JMC 工具主要由三個組件構成：Java 進程瀏覽器、JMX 控制台和 Java Flight 記錄器等。

Java 進程瀏覽器能夠利用 Java 自帶的 JDP 協議自動發現本地或者遠程正在使用的 Java 進程;

JMX 控制台通過 JMX 接口管理監控 JDK，它能夠查看堆內存使用情況、CPU 負載等;

Java Flight Recorder 是一個內置在 JDK 中的監測和事件收集框架。收集的事件包括：磁盤 IO、GC、線程 sleep、線程 wait、Socket read/write 等。

下圖顯示了 JMC 啟動后當前機器正在運行中的所有 Java 進程，選擇一個進程進行性能監控。

 

 

如果使用的操作系統是 Mac 並且 JDK 版本為 1.8，啟動 JMC 之后可能會發現操作界面被冷凍住了你沒辦法進行任何操作。產生這種現象的原因是 JDK 在升級過程中存在一個bug，具體解決方案可以參考：

Jdk1.8 bug

1.1 JFR 內存視圖

JFR 模塊包含一般信息、內存、代碼、線程、IO、系統、事件等視圖。其中，JFR 內存視圖收集的信息非常豐富，可以獲得內測使用量、GC 配置、GC 時間、對象統計時間等統計信息。下圖展示了當前 JVM 進程 GC 時間的統計信息。

 

 

1.2 JFR 代碼視圖

JFR 代碼視圖可以很容易統計出所有 Java 包占 JVM 進程所有方法調用的總時長。該視圖很方便查看熱點類、熱點方法和熱點包的調用次數、所占比例等。JFR 還提供了 I/O 視圖、線程視圖、系統視圖從不同角度更好分析當前進程運行情況。

 

 

1.3 啟動 JFR

Java 飛行記錄器(JFR)是一種用於收集關於正在運行的 Java 應用程序的診斷和分析數據的工具。它集成到 Java 虛擬機(JVM)中，幾乎不會造成性能開銷，因此即使在負載非常大的生產環境中也可以使用它。

• 首先，JVM 進程開啟 JFR 功能需要在 JVM 啟動參數(Jvm start flags)中增加兩個參數

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder

默認情況下，JFR 在 JVM 中是禁用的。要啟用 JFR，必須使用 - XX:+FlightRecorder 選項啟動 Java 應用程序。因為 JFR 是一個商業特性，僅在基於 Java 平台、標准版(Oracle Java SE Advanced 和 Oracle Java SE Suite)的商業包中可用，所以您還必須使用 - XX:+UnlockCommercialFeatures 選項啟用商業特性。

 

 

當然，也可以配置 JMC 進行遠程監控，在啟動 Java 程序時加上如下參數：

1.  
   -Dcom.sun.management.jmxremote
2.  
   -Dcom.sun.management.jmxremote.port=18090
3.  
   -Dcom.sun.management.jmxremote.ssl=false
4.  
   -Dcom.sun.management.jmxremote.authenticate=false
5.  
   -Djava.rmi.server.hostname=192.168.149.184
6.  
   -XX:+UnlockCommercialFeatures
7.  
   -XX:+FlightRecorder

允許其它機器監控該程序，必須指定 -Djava.rmi.server.hostname=，如果不指定該配置，那么就只能在本機監控該程序。

控制監控的授權(讓特定的用戶才能連接 JMX 服務)，需要設置

-Dcom.sun.management.jmxremote.authenticate=true

如果設置為 false 則不需要授權。

授權需要指定兩個文件：jmxremote.password 和 jmxremote.access，password 文件主要是配置用戶名和密碼。

• 其次，選中需要進行性能分析的進程，點擊右鍵選擇開啟飛行記錄器：

 

 

 

 

 

1.4 JFR 事件

JFR 記錄並保存事件流，JMC 提供不同的視圖來分析這些事件，但是 JFR 事件面板(如上圖所示)才是分析事件最有效的途徑。點擊事件，展開堆棧跟蹤。

 

 

從圖中可以看出，在 2 分鍾內發生了 4403 次 Hotspot JVM 事件和 161 次 Java Runtime 事件。應用程序有多個線程共消耗 73 毫秒向套接字內寫數據(Socket Write);應用程序中多個線程共消耗 120 秒從套接字讀取數據(Socket Read)。這看起來並不正常，通過查看這些事件的處理記錄可以發現，由多個線程使用阻塞式 I/O 讀取請求。這些管理請求的時間間隔通常很長，但這些線程卻在 read() 方法內被阻塞，所以導致這些線程讀取數據時消耗了過多的時間。

 

 

JFR 的事件就如黑匣子一般，通過收集的這些事件的詳細信息能夠更加深入了解程序的內部運行過程，這是很多其他工具所不具備的。

1.5 實際案例

API Gateway 是一種高並發、高流量的系統，它的主要功能是用於給第三方合作伙伴提供數據與服務的能力。因此，API Gateway 對於處理用戶請求的完整鏈路中每個環節的性能損耗都會非常敏感。

最近，在升級網關的核心功能模塊之后與測試同學一起合作對網關的某些 API 接口進行性能壓力測試，利用壓測機 Jmeter 模擬多用戶並發請求。但不管怎么增加並發數，每分鍾的請求總量穩定保持在 4 萬/min，TPS 也一直在 650 左右波動，而且所有服務器的 CPU、內存、網絡、IO 占用率均不高。

針對這種情況，我們首先排除了業務方的性能問題，因此直接對業務方(2 核 8G)發起並發請求，TPS 都可以達到 800 左右的並發數。其次，我們也排除了接入層 SLB、OpenResty 的問題，因為網關未升級核心功能情況下單台網關的 TPS 很容易達到 4000 左右。

因此，根據以上分析基本可以確定性能瓶頸出在網關處理請求的過程中。

在網關的 JVM 啟動參數中增加 JFR 啟動參數：

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder

 

 

使用 JFR 的事件視圖點擊堆棧跟蹤，就可以查看到代碼調用鏈，看到自己的業務代碼，從而定位到最耗時的代碼位置。

下圖很清楚展示了來自客戶端每個請求主要的事件都耗費在調用 Redis 讀取 API 元信息，每一次讀取源信息都需要進行序列化與反序列化，導致平均響應時間增加網關處理請求時間加長，因此 TPS 下降並一直穩定在某個值。解決方案 API 元信息盡可能緩存到本地 JVM 內存，優先從本地內存讀取數據減少訪問 Redis 頻次。

 

 

當然系統 TPS 上不去的原因也不能僅僅從單一維度分析，要綜合起來多維度進行分析，如網絡帶寬、連接池、Java 內存管理、HTTP 通信機制、業務邏輯、系統架構(緩存、數據庫等)等等。

2. Tprofiler

TProfiler 是淘寶開源的一個可以在生產環境長期使用的性能分析工具。它同時支持剖析和采樣兩種方式，記錄方法執行的時間和次數，生成方法熱點、對象熱點、線程狀態分析等數據，為查找系統性能瓶頸提供數據支持。

TProfiler 在 JVM 啟動時把時間采集程序注入到字節碼中，整個過程無需修改應用源碼。運行時會把數據寫到日志文件，一般情況下每小時輸出的日志小於 50M。目前 TProfiler 已應用於淘寶的核心 Java 前端系統，部署后低峰期對應用響應時間影響 20% 高峰期對吞吐量大約有 30% 的降低。

2.1 配置部署

• 安裝 TProfiler
  直接下載完整安裝包或者下載源碼運行 package.bat 腳本或者執行 mvn assembly:assembly命令生成 tprofiler.jar 即可。
• 配置 profile.properties

profile.properties 作為 tprofiler.jar 的配置文件，可以根據實際情況進行調整。

1.  
   #log file name
2.  
   logFileName = tprofiler.log
3.  
   methodFileName = tmethod.log
4.  
   samplerFileName = tsampler.log
5.  
   #basic configuration items
6.  
   startProfTime = 19:00:00 #開始進行profile的時間
7.  
   endProfTime = 23:00:00 #結束profile的時間
8.  
   eachProfUseTime = 5 #profile時間長度(單位秒)
9.  
   eachProfIntervalTime = 50#兩次profile的時間間隔（單位秒）
10.  
    samplerIntervalTime = 20 #兩次采樣的時間間隔
11.  
    port = 50000
12.  
    debugMode = false
13.  
    needNanoTime = false
14.  
    ignoreGetSetMethod = true
15.  
    #file paths
16.  
    logFilePath = /home/admin/tprofiler/logs/${logFileName}
17.  
    methodFilePath = /home/admin/tprofiler/logs/${methodFileName}
18.  
    samplerFilePath = /home/admin/tprofiler/logs/${samplerFileName}
19.  
    #include & excludes items
20.  
    excludeClassLoader = org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader
21.  
    includePackageStartsWith = com.taobao;com.taobao.common
22.  
    excludePackageStartsWith = com.taobao.sketch;org.apache.velocity;com.alibaba;com.taobao.forest.domain.dataobject

• 配置 JVM 進程

在 JVM 啟動參數中添加，然后重啟應用。

1.  
   - javaagent:/home/admin/tprofiler/lib/tprofiler.jar
2.  
   -Dprofile.properties= /home/admin/tprofiler/lib/profile.properties

• 遠程操作

1.  
   java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] status #遠程查看狀態操作
2.  
   java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] start #遠程開始操作
3.  
   java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] stop #遠程停止操作
4.  
   java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] flushmethod #遠程刷出方法數據

 

 

2.2 TProfiler 性能方法的采集

TProfiler 能夠生成日志：tmethod.log、tprofiler.log、tsampler.log。

普通方法、線程信息統計
執行如下命令，會生成 method.log 和 thread.log：

java -cp ../lib/tprofiler-1.0.1.jar com.taobao.profile.analysis.SamplerLogAnalysis tsampler.log method.log thread.log

method.log 文件格式說明：

1.  
   方法信息 采樣過程中方法出現次數
2.  
   org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn. java:1131) 54
3.  
   org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn. java:498) 54
4.  
   org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable. java:108) 36
5.  
   org.jboss.netty.util.internal.DeadLockProofWorker$ 1.run(DeadLockProofWorker.java:44) 36
6.  
   org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker. java:163) 36
7.  
   org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil. java:38) 36
8.  
   org.I0Itec.zkclient.ZkEventThread.run(ZkEventThread. java:67) 36
9.  
   com.alibaba.dubbo.remoting.exchange.support.DefaultFuture$RemotingInvocationTimeoutScan.run(DefaultFuture. java:300) 18
10.  
    com.taobao.profile.thread.TimeControlThread.run(TimeControlThread. java:116) 18
11.  
    com.taobao.profile.thread.SamplerThread.run(SamplerThread. java:57) 18
12.  
    com.taobao.profile.thread.TimeControlThread.await(TimeControlThread. java:84) 18
13.  
    com.taobao.profile.thread.InnerSocketThread.run(InnerSocketThread. java:44) 18
14.  
    com.taobao.profile.thread.DataDumpThread.run(DataDumpThread. java:69) 17
15.  
    org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool. java:492) 1
16.  
    org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool. java:363) 1
17.  
    com.taobao.profile.thread.DataDumpThread.run(DataDumpThread. java:62) 1

thread.log 文件格式說明：

1.  
   線程信息 采樣過程中線程出現次數
2.  
   26 ZkClient-EventThread-26-192.168.150.149:2181 WAITING 18
3.  
   3 Finalizer WAITING 18
4.  
   47 DubboResponseTimeoutScanTimer TIMED_WAITING 18
5.  
   36 New I/O client worker #1-1 RUNNABLE 18
6.  
   29 DubboRegistryFailedRetryTimer-thread-1 TIMED_WAITING 18
7.  
   30 ZkClient-EventThread-30-192.168.150.149:2181 WAITING 18
8.  
   27 main-SendThread(192.168.150.149:2181) RUNNABLE 18
9.  
   31 main-SendThread(192.168.150.149:2181) RUNNABLE 18
10.  
    8 TProfiler-DataDump TIMED_WAITING 18
11.  
    52 DestroyJavaVM RUNNABLE 18
12.  
    12 VM JFR Buffer Thread RUNNABLE 18
13.  
    49 global-client-idle-conn-cleanup-scheduler-4-1 TIMED_WAITING 18
14.  
    5 Signal Dispatcher RUNNABLE 18
15.  
    40 commons-pool-EvictionTimer TIMED_WAITING 18
16.  
    23 main-EventThread WAITING 18
17.  
    10 JFR request timer WAITING 18
18.  
    6 TProfiler-TimeControl TIMED_WAITING 18
19.  
    32 main-EventThread WAITING 18
20.  
    46 jupiter-0-ClientToProxyAcceptor-0 RUNNABLE 18
21.  
    9 TProfiler-Sampler RUNNABLE 18
22.  
    28 main-EventThread WAITING 18
23.  
    2 Reference Handler WAITING 18
24.  
    45 ObjectCleanerThread TIMED_WAITING 18
25.  
    22 main-SendThread(192.168.150.199:2181) RUNNABLE 18
26.  
    19 RMI TCP Accept-0 RUNNABLE 18
27.  
    48 print-cache-job-1 TIMED_WAITING 18
28.  
    7 TProfiler-InnerSocket RUNNABLE 18
29.  
    43 dubbo-remoting-client-heartbeat-thread-2 WAITING 18
30.  
    50 rxnetty-nio-eventloop-2-1 RUNNABLE 18
31.  
    33 DubboSaveRegistryCache-thread-1 WAITING 18
32.  
    42 New I/O client worker #1-2 RUNNABLE 18
33.  
    17 RMI TCP Accept-0 RUNNABLE 18
34.  
    18 RMI TCP Accept-18090 RUNNABLE 18
35.  
    34 DubboClientReconnectTimer-thread-1 WAITING 10
36.  
    54 jupiter-0-ClientToProxyWorker-1 RUNNABLE 10
37.  
    60 jupiter-0-ProxyToServerWorker-1 RUNNABLE 10
38.  
    58 jupiter-0-ProxyToServerWorker-2 RUNNABLE 10
39.  
    53 jupiter-0-ClientToProxyWorker-0 RUNNABLE 10
40.  
    41 DubboClientReconnectTimer-thread-2 TIMED_WAITING 10
41.  
    57 jupiter-0-ProxyToServerWorker-0 RUNNABLE 10
42.  
    55 jupiter-0-ClientToProxyWorker-2 RUNNABLE 10
43.  
    56 jupiter-0-ClientToProxyWorker-3 RUNNABLE 10
44.  
    59 jupiter-0-ProxyToServerWorker-3 RUNNABLE 10
45.  
    41 DubboClientReconnectTimer-thread-2 WAITING 8
46.  
    34 DubboClientReconnectTimer-thread-1 TIMED_WAITING 8
47.  
    37 DubboClientHandler-192.168.149.183:20880-thread-1 TIMED_WAITING 3
48.  
    35 NettyClientBoss-thread-1 TIMED_WAITING 2
49.  
    44 DubboClientHandler-192.168.150.149:20892-thread-1 TIMED_WAITING 2
50.  
    35 NettyClientBoss-thread-1 TERMINATED 1

• top 熱點方法、熱點對象信息統計

執行如下命令，生成 topmethod.log 和 topobject.log 文件

java -cp ../lib/tprofiler-1.0.1.jar com.taobao.profile.analysis.ProfilerLogAnalysis tprofiler.log tmethod.log topmethod.log topobject.log

topmethod.log 文件格式說明：

1.  
   方法信息 執行次數 平均執行時間 全部執行時間
2.  
   cn /com/company/xqy/framework/cacheframework/rediscache/RedisFactory:getJedisCache:107 750 7 5451
3.  
   cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:checkObjectKeyExisted:243 516 3 1524
4.  
   cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:get:180 563 3 1493
5.  
   cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:getString:839 572 2 1199
6.  
   cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:incr:1144 353 2 727
7.  
   cn /com/company/xqy/jupiter/gateway/netty/ClientToProxyHandler:channelRead0:357 356 2 646
8.  
   cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/RateLimiterRequestFilter:doFilter:114 358 1 533
9.  
   cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:ttl:1176 214 2 447
10.  
    cn /com/company/xqy/jupiter/gateway/netty/ClientToProxyHandler$2:onCompleted:354 263 1 316
11.  
    cn /com/company/xqy/framework/cacheframework/rediscache/RedisUtil:unseriallize:78 80 3 258
12.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/AuthenticationFilter:doFilter:126 310 1 237
13.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/HttpRequestFilterChain:doFilter:72 358 0 137
14.  
    cn /com/company/xqy/jupiter/gateway/component/cache/service/VaultCacheServiceImpl:getAppSecretByAppKey:52 237 0 73
15.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:writeRequest:183 25 2 56
16.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/ProxyToServerHandler:channelRead0:70 266 0 45
17.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/log/TraceUtils:createTraceId:39 1 44 44
18.  
    cn /com/company/xqy/jupiter/gateway/util/ComponentUtil:getRedisConfig:52 1 44 44
19.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:sendRequest:98 50 1 40
20.  
    cn /com/company/xqy/jupiter/gateway/util/ToString:toString:20 7 5 37
21.  
    cn /com/company/xqy/framework/log/LoggerUtils:info:31 13 2 29
22.  
    cn /com/company/xqy/jupiter/gateway/netty/HttpProxyServer$1:initChannel:142 12 2 28
23.  
    cn /com/company/xqy/jupiter/gateway/netty/uri/PatternRequest:matchingPattern:53 9 2 22
24.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:sendRequestWithNewChannel:124 9 2 19
25.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/servlet/NettyHttpServletRequest:getParameter:114 4 4 15
26.  
    cn /com/company/xqy/framework/log/LoggerUtils:format:150 5 3 14
27.  
    cn /com/company/xqy/jupiter/gateway/component/cache/service/ApiAuthSerivceImpl:checkApiAuth:54 271 0 13
28.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/AuthenticationFilter:getAppSecret:188 239 0 11
29.  
    cn /com/company/xqy/jupiter/gateway/netty/HttpProxyServer:newHttpServerCodec:171 3 3 9
30.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/AuthenticationFilter:buildParams:246 5 2 8
31.  
    cn /com/company/xqy/jupiter/gateway/component/compatible/CompatibleRequestUtil:fetchParameterModel:127 7 1 7
32.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersRunner:clientToProxyRequest:35 358 0 7
33.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/FilterUtil:getHeaderValue:30 1 6 6
34.  
    cn /com/company/xqy/jupiter/gateway/util/PathUtils:getRegularPath:27 2 3 5
35.  
    cn /com/company/xqy/jupiter/gateway/netty/uri/ExtendedAntPathMatcher:match:36 2 3 5
36.  
    cn /com/company/xqy/framework/cacheframework/rediscache/RedisFactory:returnResource:136 3 2 5
37.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/lb/WeightedRoundRobinLoadBalance:gcd:39 2 2 4
38.  
    cn /com/company/xqy/jupiter/gateway/component/security/sign/HmacSHA256Signature:sign:38 2 2 4
39.  
    cn /com/company/xqy/jupiter/gateway/netty/ClientToProxyHandler:channelInactive:395 14 0 4
40.  
    cn /com/company/xqy/jupiter/gateway/netty/channel/Channels:isChannelValid:32 1 4 4
41.  
    cn /com/company/xqy/jupiter/gateway/netty/channel/ChannelManager:tryToOfferChannelToPool:142 1 3 3
42.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/ProxyToServerHandler:channelRead0:24 266 0 3
43.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:printProxyToServerLog:215 1 2 2
44.  
    cn /com/company/xqy/jupiter/gateway/netty/uri/UrlPathUtils:getCanonicalizedPath:31 3 1 2
45.  
    cn /com/company/xqy/jupiter/gateway/component/cache/RouteCacheComponent:getAllApiConfigs:225 355 0 2
46.  
    cn /com/company/xqy/jupiter/gateway/component/SpringContextHolder:getBean:20 1 2 2
47.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/servlet/NettyHttpServletRequest:getHeader:162 1 2 2
48.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/lb/Server:hashCode:169 1 2 2
49.  
    cn /com/company/xqy/jupiter/client/utils/UrlUtils:normalizedPath:62 1 2 2
50.  
    cn /com/company/xqy/framework/cacheframework/rediscache/RedisFactory:getShardedJedisPool:111 1 2 2
51.  
    cn /com/company/xqy/jupiter/gateway/netty/ClientToProxyHandler:checkPathValidity:378 10 0 2
52.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/log/TraceLogContext:getTraceIdForLog:80 1 2 2
53.  
    cn /com/company/xqy/jupiter/gateway/netty/ClientToProxyHandler:channelRead0:54 356 0 2
54.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyResponseFuture:<init>:50 1 2 2
55.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersAdapter:<init>:29 1 2 2
56.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:sendRequestWithOpenChannel:142 25 0 1
57.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/HttpRequestUtils:isJsonRequest:62 1 0 0
58.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/lb/WeightedRoundRobinLoadBalance:select:96 2 0 0
59.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/lb/WeightedRoundRobinLoadBalance:getGCDForServers:54 2 0 0
60.  
    cn /com/company/xqy/jupiter/gateway/netty/HttpProxyServer$1:initChannel:130 12 0 0
61.  
    cn /com/company/xqy/jupiter/gateway/component/compatible/CompatibleRequestUtil:getParameterAppKey:24 5 0 0
62.  
    cn /com/company/xqy/jupiter/gateway/netty/channel/ChannelUtils:getTraceIdForLog:32 1 0 0
63.  
    cn /com/company/xqy/jupiter/gateway/component/compatible/CompatibleRequestUtil:getParameterVersion:64 1 0 0
64.  
    cn /com/company/xqy/jupiter/gateway/component/security/sign/AbstractSignature:sign:57 2 0 0
65.  
    cn /com/company/xqy/jupiter/gateway/component/security/sign/AbstractSignature:sign:46 2 0 0
66.  
    cn /com/company/xqy/jupiter/gateway/component/compatible/CompatibleRequestUtil:getParameterTimestamp:54 1 0 0
67.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/ParameterValidationFilter:doFilter:74 1 0 0
68.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/SimpleChannelFutureListener:operationComplete:8 1 0 0
69.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/SimpleChannelFutureListener:operationComplete:18 1 0 0
70.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender$2:onSuccess:175 1 0 0
71.  
    cn /com/company/xqy/jupiter/gateway/netty/HttpProxyServer:access$200:38 3 0 0
72.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/chain/request/pre/AuthenticationFilter:computeSign:165 2 0 0
73.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersRunner:<init>:22 1 0 0
74.  
    cn /com/company/xqy/jupiter/gateway/util/ComponentUtil:getRedisCacheClient:48 1 0 0
75.  
    cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyRequestSender:sendRequest:58 50 0 0
76.  
    cn /com/company/xqy/framework/cacheframework/rediscache/ShardedJedisClient:isExist:227 516 0 0
77.  
    cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersProviderAdapter:filterRequest:13 1 0 0

topobject.log 文件格式說明：

1.  
   方法信息 執行次數 平均執行時間 全部執行時間
2.  
   cn /com/company/xqy/jupiter/gateway/netty/upstream/NettyResponseFuture:<init>:50 1 2 2
3.  
   cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersAdapter:<init>:29 1 2 2
4.  
   cn /com/company/xqy/jupiter/gateway/netty/filter/HttpFiltersRunner:<init>:22 1 0 0

這是壓測多次時隨機挑選的一次結果。熱點方法和熱點代碼尤其值得我們關注，因此及其有可能是代碼瓶頸所在。這些熱點代碼一般要么是平均響應時間高一些，要是產生的臨時對象會多一些。

3. Jprofiler

JProfiler 是由 ej-technologies 公司開發的一款性能瓶頸分析工具。它是一款優秀的商業軟件，功能非常豐富，因此具備一些免費軟件所不具備的功能。Jprofiler 提供的主要功能有內存視圖、CPU 視圖、線程視圖、堆遍歷器(Heap Walker)等。

3.1 Jprofiler 使用

CPU 視圖可以查看各個函數的 CPU 占用時間。Hot Spots 顯示消耗時間最多的方法的列表，它不僅給出了單個函數的 CPU 使用時間和方法調用次數，同時還能顯示函數調用堆棧信息，方便定位問題。

 

 

在線程視圖可以統計並查詢當前 JVM 所有線程的運行狀態，線程持有鎖的狀態並且可 dump 線程。

 

 

4. Arthas

Arthas 是阿里最近剛剛開源的 Java 生成環境診斷工具。

Arthas 支持在 Linux/Unix/Mac 等平台上進行一鍵安裝，現在處於試用於反饋階段，感興趣的同學可以自己研究試用。

5.Conclusion

本文介紹了常用的性能分析工具和故障排查工具，希望可以幫助開發人員在排查性能問題的時候快速定位到性瓶頸。每個工具都有其優勢與劣勢，只有更好了解問題所出現的場景，理清解決問題的思路，才能最大化的發揮工具的價值。