Java 性能瓶頸分析工具 你知道幾個?
0. Introduction
Java 性能優(yōu)化分為很多個方面,如系統(tǒng)優(yōu)化、算法優(yōu)化、代碼優(yōu)化等。代碼優(yōu)化是指開發(fā)人員在研發(fā)、測試過程中使用性能瓶頸分析工具快速定位出由于編碼存在的性能瓶頸問題并持續(xù)進(jìn)行優(yōu)化。一種很常見的場景是測試同學(xué)在對服務(wù)進(jìn)行壓測時,無論怎么增加并發(fā)應(yīng)用的 TPS 一直保持在某個值進(jìn)行左右波動,這個時候要怎么排查呢。為了可以準(zhǔn)確獲得運(yùn)行過程中程序的性能數(shù)據(jù),性能調(diào)優(yōu)人員和開發(fā)者需要使用性能分析(profiling)輔助工具從全局視角來查看系統(tǒng)的運(yùn)行狀況。本文主要介紹通過熟練掌握 JMC、Tprofiler、JProfiler 等各種性能瓶頸分析工具,進(jìn)而提高定位性能瓶頸、系統(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 進(jìn)程瀏覽器、JMX 控制臺和 Java Flight 記錄器等。
Java 進(jìn)程瀏覽器能夠利用 Java 自帶的 JDP 協(xié)議自動發(fā)現(xiàn)本地或者遠(yuǎn)程正在使用的 Java 進(jìn)程;
JMX 控制臺通過 JMX 接口管理監(jiān)控 JDK,它能夠查看堆內(nèi)存使用情況、CPU 負(fù)載等;
Java Flight Recorder 是一個內(nèi)置在 JDK 中的監(jiān)測和事件收集框架。收集的事件包括:磁盤 IO、GC、線程 sleep、線程 wait、Socket read/write 等。
下圖顯示了 JMC 啟動后當(dāng)前機(jī)器正在運(yùn)行中的所有 Java 進(jìn)程,選擇一個進(jìn)程進(jìn)行性能監(jiān)控。

如果使用的操作系統(tǒng)是 Mac 并且 JDK 版本為 1.8,啟動 JMC 之后可能會發(fā)現(xiàn)操作界面被冷凍住了你沒辦法進(jì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)計信息。下圖展示了當(dāng)前 JVM 進(jìn)程 GC 時間的統(tǒng)計信息。

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

1.3 啟動 JFR
Java 飛行記錄器(JFR)是一種用于收集關(guān)于正在運(yùn)行的 Java 應(yīng)用程序的診斷和分析數(shù)據(jù)的工具。它集成到 Java 虛擬機(jī)(JVM)中,幾乎不會造成性能開銷,因此即使在負(fù)載非常大的生產(chǎn)環(huán)境中也可以使用它。
- 首先,JVM 進(jìn)程開啟 JFR 功能需要在 JVM 啟動參數(shù)(Jvm start flags)中增加兩個參數(shù)
- -XX:+UnlockCommercialFeatures -XX:+FlightRecorder
默認(rèn)情況下,JFR 在 JVM 中是禁用的。要啟用 JFR,必須使用 - XX:+FlightRecorder 選項啟動 Java 應(yīng)用程序。因為 JFR 是一個商業(yè)特性,僅在基于 Java 平臺、標(biāo)準(zhǔn)版(Oracle Java SE Advanced 和 Oracle Java SE Suite)的商業(yè)包中可用,所以您還必須使用 - XX:+UnlockCommercialFeatures 選項啟用商業(yè)特性。

當(dāng)然,也可以配置 JMC 進(jìn)行遠(yuǎn)程監(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
允許其它機(jī)器監(jiān)控該程序,必須指定 -Djava.rmi.server.hostname=,如果不指定該配置,那么就只能在本機(jī)監(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 文件主要是配置用戶名和密碼。
- 其次,選中需要進(jìn)行性能分析的進(jìn)程,點(diǎn)擊右鍵選擇開啟飛行記錄器:


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

從圖中可以看出,在 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 的事件就如黑匣子一般,通過收集的這些事件的詳細(xì)信息能夠更加深入了解程序的內(nèi)部運(yùn)行過程,這是很多其他工具所不具備的。
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 接口進(jìn)行性能壓力測試,利用壓測機(jī) 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 都可以達(dá)到 800 左右的并發(fā)數(shù)。其次,我們也排除了接入層 SLB、OpenResty 的問題,因為網(wǎng)關(guān)未升級核心功能情況下單臺網(wǎng)關(guān)的 TPS 很容易達(dá)到 4000 左右。
因此,根據(jù)以上分析基本可以確定性能瓶頸出在網(wǎng)關(guān)處理請求的過程中。
在網(wǎng)關(guān)的 JVM 啟動參數(shù)中增加 JFR 啟動參數(shù):
- -XX:+UnlockCommercialFeatures -XX:+FlightRecorder

使用 JFR 的事件視圖點(diǎn)擊堆棧跟蹤,就可以查看到代碼調(diào)用鏈,看到自己的業(yè)務(wù)代碼,從而定位到最耗時的代碼位置。
下圖很清楚展示了來自客戶端每個請求主要的事件都耗費(fèi)在調(diào)用 Redis 讀取 API 元信息,每一次讀取源信息都需要進(jìn)行序列化與反序列化,導(dǎo)致平均響應(yīng)時間增加網(wǎng)關(guān)處理請求時間加長,因此 TPS 下降并一直穩(wěn)定在某個值。解決方案 API 元信息盡可能緩存到本地 JVM 內(nèi)存,優(yōu)先從本地內(nèi)存讀取數(shù)據(jù)減少訪問 Redis 頻次。

當(dāng)然系統(tǒng) TPS 上不去的原因也不能僅僅從單一維度分析,要綜合起來多維度進(jìn)行分析,如網(wǎng)絡(luò)帶寬、連接池、Java 內(nèi)存管理、HTTP 通信機(jī)制、業(yè)務(wù)邏輯、系統(tǒng)架構(gòu)(緩存、數(shù)據(jù)庫等)等等。
2. Tprofiler
TProfiler 是淘寶開源的一個可以在生產(chǎn)環(huán)境長期使用的性能分析工具。它同時支持剖析和采樣兩種方式,記錄方法執(zhí)行的時間和次數(shù),生成方法熱點(diǎn)、對象熱點(diǎn)、線程狀態(tài)分析等數(shù)據(jù),為查找系統(tǒng)性能瓶頸提供數(shù)據(jù)支持。
TProfiler 在 JVM 啟動時把時間采集程序注入到字節(jié)碼中,整個過程無需修改應(yīng)用源碼。運(yùn)行時會把數(shù)據(jù)寫到日志文件,一般情況下每小時輸出的日志小于 50M。目前 TProfiler 已應(yīng)用于淘寶的核心 Java 前端系統(tǒng),部署后低峰期對應(yīng)用響應(yīng)時間影響 20% 高峰期對吞吐量大約有 30% 的降低。
2.1 配置部署
- 安裝 TProfiler
直接下載完整安裝包或者下載源碼運(yùn)行 package.bat 腳本或者執(zhí)行 mvn assembly:assembly命令生成 tprofiler.jar 即可。
- 配置 profile.properties
profile.properties 作為 tprofiler.jar 的配置文件,可以根據(jù)實際情況進(jìn)行調(diào)整。
- #log file name
- logFileName = tprofiler.log
- methodFileName = tmethod.log
- samplerFileName = tsampler.log
- #basic configuration items
- startProfTime = 19:00:00 #開始進(jìn)行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 進(jìn)程
在 JVM 啟動參數(shù)中添加,然后重啟應(yīng)用。
- -javaagent:/home/admin/tprofiler/lib/tprofiler.jar
- -Dprofile.properties=/home/admin/tprofiler/lib/profile.properties
- 遠(yuǎn)程操作
- java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] status #遠(yuǎn)程查看狀態(tài)操作
- java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] start #遠(yuǎn)程開始操作
- java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] stop #遠(yuǎn)程停止操作
- java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [192.168.132.*.*] [port] flushmethod #遠(yuǎn)程刷出方法數(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 熱點(diǎn)方法、熱點(diǎn)對象信息統(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
這是壓測多次時隨機(jī)挑選的一次結(jié)果。熱點(diǎn)方法和熱點(diǎn)代碼尤其值得我們關(guān)注,因此及其有可能是代碼瓶頸所在。這些熱點(diǎn)代碼一般要么是平均響應(yīng)時間高一些,要是產(chǎn)生的臨時對象會多一些。
3. Jprofiler
JProfiler 是由 ej-technologies 公司開發(fā)的一款性能瓶頸分析工具。它是一款優(yōu)秀的商業(yè)軟件,功能非常豐富,因此具備一些免費(fèi)軟件所不具備的功能。Jprofiler 提供的主要功能有內(nèi)存視圖、CPU 視圖、線程視圖、堆遍歷器(Heap Walker)等。
3.1 Jprofiler 使用
CPU 視圖可以查看各個函數(shù)的 CPU 占用時間。Hot Spots 顯示消耗時間最多的方法的列表,它不僅給出了單個函數(shù)的 CPU 使用時間和方法調(diào)用次數(shù),同時還能顯示函數(shù)調(diào)用堆棧信息,方便定位問題。

在線程視圖可以統(tǒng)計并查詢當(dāng)前 JVM 所有線程的運(yùn)行狀態(tài),線程持有鎖的狀態(tài)并且可 dump 線程。

4. Arthas
Arthas 是阿里最近剛剛開源的 Java 生成環(huán)境診斷工具。
Arthas 支持在 Linux/Unix/Mac 等平臺上進(jìn)行一鍵安裝,現(xiàn)在處于試用于反饋階段,感興趣的同學(xué)可以自己研究試用。
5.Conclusion
本文介紹了常用的性能分析工具和故障排查工具,希望可以幫助開發(fā)人員在排查性能問題的時候快速定位到性瓶頸。每個工具都有其優(yōu)勢與劣勢,只有更好了解問題所出現(xiàn)的場景,理清解決問題的思路,才能***化的發(fā)揮工具的價值。