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

0. Introduction

Java 性能優(yōu)化分為很多個方面拜马，如系統(tǒng)優(yōu)化、算法優(yōu)化沐绒、代碼優(yōu)化等俩莽。代碼優(yōu)化是指開發(fā)人員在研發(fā)、測試過程中使用性能瓶頸分析工具快速定位出由于編碼存在的性能瓶頸問題并持續(xù)進行優(yōu)化乔遮。一種很常見的場景是測試同學(xué)在對服務(wù)進行壓測時扮超，無論怎么增加并發(fā)應(yīng)用的 TPS 一直保持在某個值進行左右波動，這個時候要怎么排查呢蹋肮。為了可以準確獲得運行過程中程序的性能數(shù)據(jù)出刷，性能調(diào)優(yōu)人員和開發(fā)者需要使用性能分析(profiling)輔助工具從全局視角來查看系統(tǒng)的運行狀況。本文主要介紹通過熟練掌握 JMC坯辩、Tprofiler馁龟、JProfiler 等各種性能瓶頸分析工具，進而提高定位性能瓶頸漆魔、系統(tǒng)故障排查能力坷檩。

1. Java Mission Control

JMC(Java 任務(wù)控制)是 Java 7u40 新增加的性能監(jiān)控工具。目前改抡，Oracle Java 官方在今年 5 月份已經(jīng)公布 Java Mission Control(JMC)的源代碼已正式開源矢炼，此舉得到了 Java 開發(fā)社區(qū)的高度贊賞。

JMC 源碼地址： JMC source code

JMC 工具主要由三個組件構(gòu)成：Java 進程瀏覽器阿纤、JMX 控制臺和 Java Flight 記錄器等句灌。

Java 進程瀏覽器能夠利用 Java 自帶的 JDP 協(xié)議自動發(fā)現(xiàn)本地或者遠程正在使用的 Java 進程;

JMX 控制臺通過 JMX 接口管理監(jiān)控 JDK，它能夠查看堆內(nèi)存使用情況阵赠、CPU 負載等;

Java Flight Recorder 是一個內(nèi)置在 JDK 中的監(jiān)測和事件收集框架涯塔。收集的事件包括：磁盤 IO肌稻、GC、線程 sleep匕荸、線程 wait爹谭、Socket read/write 等。

下圖顯示了 JMC 啟動后當前機器正在運行中的所有 Java 進程榛搔，選擇一個進程進行性能監(jiān)控诺凡。

如果使用的操作系統(tǒng)是 Mac 并且 JDK 版本為 1.8，啟動 JMC 之后可能會發(fā)現(xiàn)操作界面被冷凍住了你沒辦法進行任何操作践惑。產(chǎn)生這種現(xiàn)象的原因是 JDK 在升級過程中存在一個bug腹泌，具體解決方案可以參考：

Jdk1.8 bug

1.1 JFR 內(nèi)存視圖

JFR 模塊包含一般信息、內(nèi)存尔觉、代碼凉袱、線程、IO侦铜、系統(tǒng)专甩、事件等視圖。其中钉稍，JFR 內(nèi)存視圖收集的信息非常豐富涤躲，可以獲得內(nèi)測使用量、GC 配置贡未、GC 時間种樱、對象統(tǒng)計時間等統(tǒng)計信息。下圖展示了當前 JVM 進程 GC 時間的統(tǒng)計信息俊卤。

1.2 JFR 代碼視圖

JFR 代碼視圖可以很容易統(tǒng)計出所有 Java 包占 JVM 進程所有方法調(diào)用的總時長嫩挤。該視圖很方便查看熱點類、熱點方法和熱點包的調(diào)用次數(shù)瘾蛋、所占比例等俐镐。JFR 還提供了 I/O 視圖矫限、線程視圖哺哼、系統(tǒng)視圖從不同角度更好分析當前進程運行情況。

1.3 啟動 JFR

Java 飛行記錄器(JFR)是一種用于收集關(guān)于正在運行的 Java 應(yīng)用程序的診斷和分析數(shù)據(jù)的工具叼风。它集成到 Java 虛擬機(JVM)中取董，幾乎不會造成性能開銷，因此即使在負載非常大的生產(chǎn)環(huán)境中也可以使用它无宿。

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

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder 

默認情況下，JFR 在 JVM 中是禁用的孽鸡。要啟用 JFR蹂午，必須使用 - XX:+FlightRecorder 選項啟動 Java 應(yīng)用程序栏豺。因為 JFR 是一個商業(yè)特性，僅在基于 Java 平臺豆胸、標準版(Oracle Java SE Advanced 和 Oracle Java SE Suite)的商業(yè)包中可用奥洼，所以您還必須使用 - XX:+UnlockCommercialFeatures 選項啟用商業(yè)特性。

當然晚胡，也可以配置 JMC 進行遠程監(jiān)控灵奖，在啟動 Java 程序時加上如下參數(shù)：

-Dcom.sun.management.jmxremote  
-Dcom.sun.management.jmxremote.port=18090  
-Dcom.sun.management.jmxremote.ssl=false  
-Dcom.sun.management.jmxremote.authenticate=false  
-Djava.rmi.server.hostname=192.168.149.184  
-XX:+UnlockCommercialFeatures  
-XX:+FlightRecorder 

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

控制監(jiān)控的授權(quán)(讓特定的用戶才能連接 JMX 服務(wù))遣妥，需要設(shè)置

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

如果設(shè)置為 false 則不需要授權(quán)擅编。

授權(quán)需要指定兩個文件：jmxremote.password 和 jmxremote.access，password 文件主要是配置用戶名和密碼箫踩。

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

1.4 JFR 事件

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

從圖中可以看出，在 2 分鐘內(nèi)發(fā)生了 4403 次 Hotspot JVM 事件和 161 次 Java Runtime 事件理盆。應(yīng)用程序有多個線程共消耗 73 毫秒向套接字內(nèi)寫數(shù)據(jù)(Socket Write);應(yīng)用程序中多個線程共消耗 120 秒從套接字讀取數(shù)據(jù)(Socket Read)痘煤。這看起來并不正常，通過查看這些事件的處理記錄可以發(fā)現(xiàn)猿规，由多個線程使用阻塞式 I/O 讀取請求衷快。這些管理請求的時間間隔通常很長，但這些線程卻在 read() 方法內(nèi)被阻塞姨俩，所以導(dǎo)致這些線程讀取數(shù)據(jù)時消耗了過多的時間蘸拔。

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

1.5 實際案例

API Gateway 是一種高并發(fā)、高流量的系統(tǒng)张遭，它的主要功能是用于給第三方合作伙伴提供數(shù)據(jù)與服務(wù)的能力邓萨。因此，API Gateway 對于處理用戶請求的完整鏈路中每個環(huán)節(jié)的性能損耗都會非常敏感。

最近缔恳，在升級網(wǎng)關(guān)的核心功能模塊之后與測試同學(xué)一起合作對網(wǎng)關(guān)的某些 API 接口進行性能壓力測試宝剖，利用壓測機 Jmeter 模擬多用戶并發(fā)請求。但不管怎么增加并發(fā)數(shù)歉甚，每分鐘的請求總量穩(wěn)定保持在 4 萬/min诈闺，TPS 也一直在 650 左右波動，而且所有服務(wù)器的 CPU铃芦、內(nèi)存雅镊、網(wǎng)絡(luò)、IO 占用率均不高刃滓。

針對這種情況仁烹，我們首先排除了業(yè)務(wù)方的性能問題，因此直接對業(yè)務(wù)方(2 核 8G)發(fā)起并發(fā)請求咧虎，TPS 都可以達到 800 左右的并發(fā)數(shù)卓缰。其次，我們也排除了接入層 SLB砰诵、OpenResty 的問題征唬，因為網(wǎng)關(guān)未升級核心功能情況下單臺網(wǎng)關(guān)的 TPS 很容易達到 4000 左右。

因此茁彭，根據(jù)以上分析基本可以確定性能瓶頸出在網(wǎng)關(guān)處理請求的過程中总寒。

在網(wǎng)關(guān)的 JVM 啟動參數(shù)中增加 JFR 啟動參數(shù)：

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder 

使用 JFR 的事件視圖點擊堆棧跟蹤，就可以查看到代碼調(diào)用鏈理肺，看到自己的業(yè)務(wù)代碼摄闸，從而定位到最耗時的代碼位置。

下圖很清楚展示了來自客戶端每個請求主要的事件都耗費在調(diào)用 Redis 讀取 API 元信息妹萨，每一次讀取源信息都需要進行序列化與反序列化年枕，導(dǎo)致平均響應(yīng)時間增加網(wǎng)關(guān)處理請求時間加長，因此 TPS 下降并一直穩(wěn)定在某個值乎完。解決方案 API 元信息盡可能緩存到本地 JVM 內(nèi)存熏兄，優(yōu)先從本地內(nèi)存讀取數(shù)據(jù)減少訪問 Redis 頻次。

當然系統(tǒng) TPS 上不去的原因也不能僅僅從單一維度分析树姨，要綜合起來多維度進行分析摩桶，如網(wǎng)絡(luò)帶寬、連接池娃弓、Java 內(nèi)存管理典格、HTTP 通信機制岛宦、業(yè)務(wù)邏輯台丛、系統(tǒng)架構(gòu)(緩存、數(shù)據(jù)庫等)等等挟鸠。

2. Tprofiler

TProfiler 是淘寶開源的一個可以在生產(chǎn)環(huán)境長期使用的性能分析工具勒葱。它同時支持剖析和采樣兩種方式，記錄方法執(zhí)行的時間和次數(shù)淮逊，生成方法熱點侠坎、對象熱點蚁趁、線程狀態(tài)分析等數(shù)據(jù)，為查找系統(tǒng)性能瓶頸提供數(shù)據(jù)支持实胸。

TProfiler 在 JVM 啟動時把時間采集程序注入到字節(jié)碼中他嫡，整個過程無需修改應(yīng)用源碼。運行時會把數(shù)據(jù)寫到日志文件庐完，一般情況下每小時輸出的日志小于 50M钢属。目前 TProfiler 已應(yīng)用于淘寶的核心 Java 前端系統(tǒng)，部署后低峰期對應(yīng)用響應(yīng)時間影響 20% 高峰期對吞吐量大約有 30% 的降低门躯。

2.1 配置部署

• 安裝 TProfiler
  直接下載完整安裝包或者下載源碼運行 package.bat 腳本或者執(zhí)行 mvn assembly:assembly命令生成 tprofiler.jar 即可淆党。

• 配置 profile.properties

profile.properties 作為 tprofiler.jar 的配置文件，可以根據(jù)實際情況進行調(diào)整讶凉。

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

• 配置 JVM 進程

在 JVM 啟動參數(shù)中添加染乌，然后重啟應(yīng)用。

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

• 遠程操作

java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] status #遠程查看狀態(tài)操作 
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] start #遠程開始操作 
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] stop #遠程停止操作 
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] flushmethod #遠程刷出方法數(shù)據(jù) 

2.2 TProfiler 性能方法的采集

TProfiler 能夠生成日志：tmethod.log懂讯、tprofiler.log荷憋、tsampler.log。

普通方法褐望、線程信息統(tǒng)計
執(zhí)行如下命令台谊，會生成 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 文件格式說明：

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

thread.log 文件格式說明：

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

• top 熱點方法、熱點對象信息統(tǒng)計

執(zhí)行如下命令譬挚，生成 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 文件格式說明：

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

topobject.log 文件格式說明：

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

這是壓測多次時隨機挑選的一次結(jié)果锅铅。熱點方法和熱點代碼尤其值得我們關(guān)注，因此及其有可能是代碼瓶頸所在减宣。這些熱點代碼一般要么是平均響應(yīng)時間高一些盐须，要是產(chǎn)生的臨時對象會多一些。

3. Jprofiler

JProfiler 是由 ej-technologies 公司開發(fā)的一款性能瓶頸分析工具漆腌。它是一款優(yōu)秀的商業(yè)軟件贼邓，功能非常豐富，因此具備一些免費軟件所不具備的功能闷尿。Jprofiler 提供的主要功能有內(nèi)存視圖塑径、CPU 視圖、線程視圖填具、堆遍歷器(Heap Walker)等统舀。

3.1 Jprofiler 使用

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

在線程視圖可以統(tǒng)計并查詢當前 JVM 所有線程的運行狀態(tài)闷串，線程持有鎖的狀態(tài)并且可 dump 線程瓮钥。

4. Arthas

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

Arthas 支持在 Linux/Unix/Mac 等平臺上進行一鍵安裝烹吵，現(xiàn)在處于試用于反饋階段碉熄，感興趣的同學(xué)可以自己研究試用。

5.Conclusion

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