TProfiler是一個能夠在生產環境長期使用的性能分析工具.它同時支持剖析和採樣兩種方式,記錄方法執行的時間和次數,生成方法熱點 對象建立熱點 線程狀態分析等數據,爲查找系統性能瓶頸提供數據支持.前端
TProfiler在JVM啓動時把時間採集程序注入到字節碼中,整個過程無需修改應用源碼.運行時會把數據寫到日誌文件,通常狀況下每小時輸出的日誌小於50M.java
業界同類開源產品都不是針對大型Web應用設計的,對性能消耗較大不能長期使用,TProfiler解決了這個問題.目前TProfiler已應用於淘寶的核心Java前端系統.node
部署後低峯期對應用響應時間影響20% 高峯期對吞吐量大約有30%的下降(高峯期能夠遠程關閉此工具)apache
1. tomcat jvm配置tprofilerbootstrap
修改catalina.sh,添加如下內容:vim
vim bin/catalina.shtomcat
JAVA_OPTS="-javaagent:/opt/tprofiler/tprofiler-1.0.1.jar -Dprofile.properties=/opt/tprofiler/profile.properties"dom
啓動tomcateclipse
sh /data/module/tomcat-7.0.42/bin/startup.shjvm
tail -f /data/module/tomcat-7.0.42/logs/catalina.out
啓動進程能夠看到tprofiler jar包文件
root 30769 1 1 12:50 pts/2 00:00:03 /data/module/jdk1.7.0_21/jre/bin/java -Djava.util.logging.config.file=/data/module/tomcat-7.0.42/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -javaagent:/opt/tprofiler/tprofiler-1.0.1.jar -Dprofile.properties=/opt/tprofiler/profile.properties -Djava.endorsed.dirs=/data/module/tomcat-7.0.42/endorsed -classpath /data/module/tomcat-7.0.42/bin/bootstrap.jar:/data/module/tomcat-7.0.42/bin/tomcat-juli.jar -Dcatalina.base=/data/module/tomcat-7.0.42 -Dcatalina.home=/data/module/tomcat-7.0.42 -Djava.io.tmpdir=/data/module/tomcat-7.0.42/temp org.apache.catalina.startup.Bootstrap start
我是用root啓動,默認在宿主目錄有logs文件夾,下面會有tprofiler生成logs文件:tmethod.log tprofiler.log tsampler.log
2. TProfiler遠程操做
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [10.232.*.*] [port] status #遠程查看狀態操做
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [10.232.*.*] [port] start #遠程開始操做
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [10.232.*.*] [port] stop #遠程中止操做
java -cp tprofiler.jar com.taobao.profile.client.TProfilerClient [10.232.*.*] [port] flushmethod #遠程刷出方法數據
寫成腳本
TPF=/opt/tprofiler/tprofiler-1.0.1.jar
COM=com.taobao.profile.client.TProfilerClient
java -cp $TPF $COM [10.232.*.*] [port] <start/stop/status/flushmethod>
3. 遠程操做驗證:
默認端口是50000,我修改成30000,其餘配置profile.properties
profile.properties默認配置:
startProfTime = 9:00:00 開始profile的時間點
endProfTime = 11:00:00 結束profile的時間點
eachProfUseTime = 5 profile時間長度(單位秒)
eachProfIntervalTime = 50 兩次profile的時間間隔(單位秒)
samplerIntervalTime = 20 兩次採樣的時間間隔(單位秒)
debugMode = false 是否進入調試模式
needNanoTime = false 是否須要用納秒記錄時間
ignoreGetSetMethod = true 是否忽略採集get/set方法
logFilePath = /home/admin/logs/tprofiler.log profile log的存放位置
methodFilePath = /home/admin/logs/tmethod.log method log的存放位置
samplerFilePath = /home/admin/logs/tsampler.log sampler log的存放位置
excludeClassLoader = org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader 不注入的類加載器(分號分割)
includePackageStartsWith = com.taobao 進行profile的類包名(分號分割)
excludePackageStartsWith = com.alibaba;com.taobao.forest.domain.dataobject 不進行profile的類包名(分號分割)
root@kinval :~# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
running
root@kinval :~# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 stop
root@kinval :~# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
stop
root@kinval :~# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 start
root@kinval :~# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
running
遠程刷出數據:
root@kinval :~/logs# java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 flushmethod
root@kinval :~/logs# cat tmethod.log
instrumentclass:0 instrumentmethod:0
instrumentclass:0 instrumentmethod:0
instrumentclass:0 instrumentmethod:0
instrumentclass:0 instrumentmethod:0
instrumentclass:0 instrumentmethod:0
4. TProfiler日誌分析
tprofiler生成日誌:
tmethod.log
tprofiler.log
tsampler.log
tprofiler.log文件格式說明:
線程ID 線程棧深度 方法ID 方法執行時間
13 2 14558 6
13 2 14554 2
13 3 14576 2
13 4 14567 2
13 2 14554 4
13 2 14556 13
java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.analysis.SamplerLogAnalysis /root/logs/tsampler.log /root/logs/method.log /root/logs/thread.log
method.log文件格式說明:
方法信息 採樣過程當中方法出現次數
org.quartz.simpl.SimpleThreadPool.getNextRunnable(SimpleThreadPool.java:428) 19728
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:518) 19728
org.quartz.simpl.SimpleThreadPool.access$000(SimpleThreadPool.java:47) 19728
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51) 17558
thread.log文件格式說明:
線程信息 採樣過程當中線程出現次數
56 DefaultQuartzScheduler_Worker-3 TIMED_WAITING 661
55 DefaultQuartzScheduler_Worker-2 TIMED_WAITING 661
60 DefaultQuartzScheduler_Worker-7 TIMED_WAITING 661
分析profiler log命令:
java -cp tprofiler.jar com.taobao.profile.analysis.ProfilerLogAnalysis /root/logs/tprofiler.log /root/logs/tmethod.log /root/logs/topmethod.log /root/logs/topobject.log
topmethod.log文件格式說明:
方法信息 執行次數 平均執行時間 所有執行時間
org/apache/velocity/runtime/parser/node/ASTBlock:render:74 38954 28 1101570
org/apache/velocity/runtime/parser/node/SimpleNode:render:338 39202 21 820064
topobject.log文件格式說明:
方法信息 執行次數 平均執行時間 所有執行時間
sketch/compile/parser/node/PropertyExecutor:<init>:32 573 1 636
sketch/util/introspection/UberspectImpl:<init>:282 34 7 241