TProfiler部署文档--笔记

TProfiler是一个可以在生产环境长期使用的性能分析工具.它同时支持剖析和采样两种方式,记录方法执行的时间和次数,生成方法热点 对象创建热点 线程状态分析等数据,为查找系统性能瓶颈提供数据支持.

TProfiler在JVM启动时把时间采集程序注入到字节码中,整个过程无需修改应用源码.运行时会把数据写到日志文件,一般情况下每小时输出的日志小于50M.

业界同类开源产品都不是针对大型Web应用设计的,对性能消耗较大不能长期使用,TProfiler解决了这个问题.目前TProfiler已应用于淘宝的核心Java前端系统.

部署后低峰期对应用响应时间影响20% 高峰期对吞吐量大约有30%的降低(高峰期可以远程关闭此工具)

1. tomcat jvm配置tprofiler

修改catalina.sh，添加以下内容：

vim bin/catalina.sh

JAVA_OPTS="-javaagent:/opt/tprofiler/tprofiler-1.0.1.jar -Dprofile.properties=/opt/tprofiler/profile.properties"

注意：/opt/tprofiler/tprofiler-1.0.1.jar表示tprofiler的全路径，在linux和windows下要根据该jar所在路径的全路径，如在windows下我的路径为D:/tprofiler/tprofiler-1.0.1.jar

启动tomcat

sh /data/module/tomcat-7.0.42/bin/startup.sh

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