初探调优4:JVM性能调优实战,从定位性能瓶颈到Tprofiler定位代码

本文涉及的产品
性能测试 PTS,5000VUM额度
日志服务 SLS,月写入数据量 50GB 1个月
简介: JVM 性能调优实战之:一次系统性能瓶颈的寻找过程   玩过性能优化的朋友都清楚,性能优化的关键并不在于怎么进行优化,而在于怎么找到当前系统的性能瓶颈。

JVM 性能调优实战之:一次系统性能瓶颈的寻找过程

 

玩过性能优化的朋友都清楚,性能优化的关键并不在于怎么进行优化,而在于怎么找到当前系统的性能瓶颈。
性能优化分为好几个层次,比如系统层次、算法层次、代码层次...JVM 的性能优化被认为是底层优化,门槛较高,精通这种技能的人比较少。笔者呆过几家技术力量不算弱的公司,每个公司内部真正能够进行 JVM 性能调优的人寥寥无几、甚至没有。如是乎,能够有效通过 JVM 调优提升系统性能的人往往被人们冠以"大牛"、"大师"之类的称呼。
其实 JVM 本身给我们提供了很多强大而有效的监控进程、分析定位瓶颈的工具,比如 JConsole、JMap、JStack、JStat 等等。使用这些命令,再结合 Linux 自身提供的一些强大的进程、线程命令,能够快速定位系统瓶颈。本文以一次使用这些工具准确定位到某系统瓶颈的实战经验为例,希望能为大家掌握 JVM 调优这项技能起到一些借鉴作用。
本文背景:

  • Linux:RedHat 6.1
  • Weblogic:11g
  • JRokit:R28.2.4
  • JDK:1.6.0_45

Weblogic 跑在 JRokit 上面,JDK 是我们对 JRokit 进行监控分析的工具。

1. LoadRunner 压测结果

该系统其实早已跑在生产上好多年,虽然没有做过压力测试,但稳定性还是可以的。公司进行架构调整,有一些新系统将对接该系统。公司领导担心对接后该系统的并发性能问题,于是开始对该系统进行并发压力测试。
50 个用户并发压十几个小时,TRT 在 20 左右,TPS 在 2.5 左右。领导对这个结果不满意,要求进行优化。但这是个老系统,开发在之前明显已经对其代码做过很多优化,如今面对这种状况也束手无策。

2. Oracle 的 awr 报告分析

有句老话,优化来优化去,系统的性能瓶颈还是会在数据库上面。在这里我们首先想到的也是数据库的问题。
并发压测的时候 Spotlight 查看数据库服务器各项性能指标,很清闲。

分析 awr 报告,结果显示也是很清闲。

并发压测的时候去相关数据表执行一些 sql 的速度很快也证明着问题不在 Oracle 这边。

3. Weblogic 服务器的性能指标

使用 Spotlight 查看并发压测时的 Weblogic 所在的 Linux 服务器,除了 CPU 之外其它各项指标显示,Linux 也很清闲。
虽然 CPU 利用率始终在 200% 左右徘徊,但这对于 16 核的系统来讲也算是正常的吧?

4. JStack 报告分析

事情到了这里,大家已经想到了线程死锁、等待的问题了。
没错,JStack 隆重登场。JStack 能够看到当前 Java 进程中每个线程的当前状态、调用栈、锁住或等待去锁定的资源,而且很强悍的是它还能直接报告是否有线程死锁,可谓解决线程问题的不二之选。
/opt/jdk1.6.0_45/bin/jstack -l 10495 > ~/10495jstack.txt
JRokit 堆栈的拉取,可以直接用 JDK 的 JStack,10495 是 Weblogic 服务的进程 ID。注意一定要用该进程的启动用户去拉,否则会报 Unable to open socket file: target process not responding or HotSpot VM not loaded 错误。
JStack 拉取的文件信息基本分为以下几个部分:

  • 该拉取快照的服务器时间
  • JVM 版本
  • 以线程 ID(即 tid)升序依次列出当前进程中每个线程的调用栈
  • 死锁(如果有的话)
  • 阻塞锁链
  • 打开的锁链
  • 监视器解锁情况跟踪

每个线程在等待什么资源,这个资源目前在被哪个线程 hold,尽在眼前。JStack 最好在压测时多次获取,找到的普遍存在的现象即为线程瓶颈所在。

4.1. TLA 空间的调整

多次拉取 JStack,发现很多线程处于这个状态:
    at jrockit/vm/Allocator.getNewTla(JJ)V(Native Method)
    at jrockit/vm/Allocator.allocObjectOrArray(Allocator.java:354)[optimized]
    at java/util/HashMap.resize(HashMap.java:564)[inlined]
    at java/util/LinkedHashMap.addEntry(LinkedHashMap.java:414)[optimized]
    at java/util/HashMap.put(HashMap.java:477)[optimized]
由此怀疑出现上述堆栈的原因可能是 TLA 空间不足引起。TLA 是 thread local area 的缩写,是每个线程私有的空间,所以在多线程环境下 TLA 带来的性能提升是显而易见的。如果大部分线程的需要分配的对象都较大,可以考虑提高 TLA 空间,因为这样更大的对象可以在 TLA 中进行分配,这样就不用担心和其它线程的同步问题了。但这个也不可以调的太大,否则也会带来一些问题,比如会带来更多内存碎片、更加频繁的垃圾搜集。
TLA 默认最小大小 2 KB,默认首选大小 16 KB - 256 KB (取决于新生代分区大小)。这里我们调整 TLA 空间大小为最小 32 KB,首选 1024 KB,JVM 启动参数中加入:
-XXtlaSize:min=32k,preferred=1024k

5. JStat 结合 GC 日志报告分析

第 4 步参数生效之后继续压测,TLA 频繁申请是降下来了,但 TRT 仍旧是 20,TPS 依旧 2.5。别灰心,改一个地方就立竿见影,胜利似乎来得太快了点。
现在怀疑是服务堆内存太小,查看一下果然。服务器物理内存 32 GB,Weblogic 进程只分到了 6 GB。怎么查看?至少有四种办法:

5.1. ps 命令

ps -ef | grep java
defonds     29874 29819  2 Sep03 ?        09:03:17 /opt/jrockit-jdk1.6.0_33/bin/java -jrockit -Xms6000m -Xmx6000m -Dweblogic.Name=AdminServer -Djava.security.policy=

5.2. Weblogic 控制台

登录 Weblogic 管理控制台 -> 环境 -> 服务器,选择该服务器实例 -> 监视 -> 性能 -> 当前堆大小。
这个页面还能看到进程已运行时间,启动以来发生的 GC 次数,可以折算出 GC 的频率,为本次性能瓶颈 - GC 过于频繁提供有力的佐证。

5.3. GC 日志报告

开启 JRokit GC 日志报告只需在 Java 进程启动参数里加入
-Xverbose:memory -Xverboselog:verboseText.txt
GC 日志将会被输出到 verboseText.txt 文件,这个文件一般会生成在启动的 Weblogic 域目录下。如果找不着也可以用 find 命令去搜:
find /appserver/ -name verboseText.txt
/appserver/Oracle/Middleware/user_projects/domains/defonds_domain/verboseText.txt
GC log 拿到后,第 3 行中的 maximal heap size 即为该进程分配到的最大堆大小:
[INFO ][memory ] Heap size: 10485760KB, maximal heap size: 10485760KB, nursery size: 5242880KB.
下面还有进程启动以后较为详细的每次 GC 的信息:
[INFO ][memory ] [YC#2547] 340.828-340.845: YC 10444109KB->10417908KB (10485760KB), 0.018 s, sum of pauses 17.294 ms, longest pause 17.294 ms.
[INFO ][memory ] [YC#2548] 340.852-340.871: YC 10450332KB->10434521KB (10485760KB), 0.019 s, sum of pauses 18.779 ms, longest pause 18.779 ms.
[INFO ][memory ] [YC#2549] 340.878-340.895: YC 10476739KB->10485760KB (10485760KB), 0.017 s, sum of pauses 16.520 ms, longest pause 16.520 ms.
[INFO ][memory ] [OC#614] 340.895-341.126: OC 10485760KB->10413562KB (10485760KB), 0.231 s, sum of pauses 206.458 ms, longest pause 206.458 ms.
第一行表示该进程启动后的第 340.828 秒 - 340.845 秒期间进行了一次 young gc,该次 GC 持续了 17.294 ms,将整个已用掉的堆内存由 10444109 KB 降低到 10417908 KB。
第三行同样是一次 young gc,但该次 GC 后已用堆内存反而上升到了 10485760 KB,也就是达到最大堆内存,于是该次 young gc 结束的同时触发 full gc。
第四行是一次 old gc (即 full gc),将已用堆内存由 10485760 KB 降到了 10413562 KB,耗时 206.458 ms。
这些日志同样能够指出当前压力下的 GC 的频率,为本次性能瓶颈 - GC 过于频繁提供有力的佐证。

5.4. JStat 报告

跟 JStack 的拉取一样,可以直接用 JDK 的 JStat 去拉取 JRokit 的 GC 信息:
/opt/jdk1.6.0_45/bin/jstat -J-Djstat.showUnsupported=true -snap 10495 > ~/10495jstat.txt
注意这个信息是一个快照,这是跟 GC 日志报告不同的地方。
jrockit.gc.latest.heapSize=10737418240
jrockit.gc.latest.nurserySize=23100384
上述是当前已用碓大小和新生代分区大小。多拉几次即可估算出各自分配的大小。

5.5. 内存分配

根据 5.1 - 5.4 我们得出当前服务器分配堆内存太小的结论,根据 5.3 GC 日志报告和 5.4. JStat 报告可以得出新生代分区太小的结论。
于是我们调整它们的大小,结合 4.1 TLA 调整的结论,JVM 启动参数增加以下:
-Xms10240m -Xmx10240m -Xns:1024m -XXtlaSize:min=32k,preferred=1024k
再次压测,TRT 降到了 2.5,TPS 上升到 20。

6. 性能瓶颈的定位

很明显,上述 JVM 调整没有从根本上解决性能问题,我们还没有真正定位到系统性能瓶颈。

6.1. 性能线程的定位

6.1.1. 性能进程的获取

使用 TOP 命令拿到最耗 CPU 的那个进程:
性能进程号的获取.png
进程 ID 为 10495 的那个进程一直在占用很高的 CPU。

6.1.2. 性能线程的获取

现在我们来找到这个进程中占用 CPU 较高的那些线程:
ps p 10495 -L -o pcpu,pid,tid,time,tname,cmd > ~/10495ps.txt
多次拉这个快照,我们找到了 tid 为 10499、10500、10501、10502 等线程一直在占用着很高的 CPU:
tid为10499、10500、10501、10502等线程占用CPU很高.png
拉 JStack 快照看看都是一些什么线程:
/opt/jdk1.6.0_45/bin/jstack -l 10495 > ~/10495jstack.txt
相关部分结果如下:
"(GC Worker Thread 1)" id=? idx=0x10 tid=10499 prio=5 alive, daemon
    at pthread_cond_wait@@GLIBC_2.3.2+202(:0)@0x3708c0b44a
    at eventTimedWaitNoTransitionImpl+71(event.c:90)@0x7fac47be8528
    at eventTimedWaitNoTransition+66(event.c:72)@0x7fac47be8593
    at mmGCWorkerThread+137(gcthreads.c:809)@0x7fac47c0774a
    at thread_stub+170(lifecycle.c:808)@0x7fac47cc15bb
    at start_thread+208(:0)@0x3708c077e1
    Locked ownable synchronizers:
        - None

"(GC Worker Thread 2)" id=? idx=0x14 tid=10500 prio=5 alive, daemon
    at pthread_cond_wait@@GLIBC_2.3.2+202(:0)@0x3708c0b44a
    at eventTimedWaitNoTransitionImpl+71(event.c:90)@0x7fac47be8528
    at eventTimedWaitNoTransition+66(event.c:72)@0x7fac47be8593
    at mmGCWorkerThread+137(gcthreads.c:809)@0x7fac47c0774a
    at thread_stub+170(lifecycle.c:808)@0x7fac47cc15bb
    at start_thread+208(:0)@0x3708c077e1
    Locked ownable synchronizers:
        - None

"(GC Worker Thread 3)" id=? idx=0x18 tid=10501 prio=5 alive, daemon
    at pthread_cond_wait@@GLIBC_2.3.2+202(:0)@0x3708c0b44a
    at eventTimedWaitNoTransitionImpl+71(event.c:90)@0x7fac47be8528
    at eventTimedWaitNoTransition+66(event.c:72)@0x7fac47be8593
    at mmGCWorkerThread+137(gcthreads.c:809)@0x7fac47c0774a
    at thread_stub+170(lifecycle.c:808)@0x7fac47cc15bb
    at start_thread+208(:0)@0x3708c077e1
    Locked ownable synchronizers:
        - None

"(GC Worker Thread 4)" id=? idx=0x1c tid=10502 prio=5 alive, daemon
    at pthread_cond_wait@@GLIBC_2.3.2+202(:0)@0x3708c0b44a
    at eventTimedWaitNoTransitionImpl+71(event.c:90)@0x7fac47be8528
    at eventTimedWaitNoTransition+66(event.c:72)@0x7fac47be8593
    at mmGCWorkerThread+137(gcthreads.c:809)@0x7fac47c0774a
    at thread_stub+170(lifecycle.c:808)@0x7fac47cc15bb
    at start_thread+208(:0)@0x3708c077e1
    Locked ownable synchronizers:
        - None

6.2. 找到性能瓶颈

事情到了这里,已经不难得出当前系统瓶颈就是频繁 GC。
为何会如此频繁 GC 呢?继续看 JStack,发现这两个互相矛盾的现象:
一方面 GC Worker 线程在拼命 GC,但是 GC 前后效果不明显,已用堆内存始终降不下来;
另一方面大量 ExecuteThread 业务处理线程处于 alloc_enqueue_allocation_and_wait_for_gc 的 native_blocked 阻塞状态。
此外,停止压测以后,查看已用堆内存大小,也就几百兆,不到分配堆内存的 1/10。
这说明了什么呢?这说明了我们应用里没有内存泄漏、静态对象不是太多、有大量的业务线程在频繁创建一些生命周期很长的临时对象。
很明显还是代码里有问题。那么这些对象来自哪里?如何在海量业务代码里边准确定位这些性能代码?也就是说如何利用 JVM 调优驱动代码层面的调优?请参考博客《JVM 性能调优实战之:使用阿里开源工具 TProfiler 在海量业务代码中精确定位性能代码》,使用 TProfiler 我们成功找到了代码里边导致 JVM 频繁 GC 的元凶,并最终解决掉了这个性能瓶颈,将 TRT 降到了 0.5,TPS 提升至 100 +。

参考资料

JVM 性能调优实战之:使用阿里开源工具 TProfiler 在海量业务代码中精确定位性能代码

置顶2016年09月21日 11:25:21

阅读数:40567

本文是《JVM 性能调优实战之:一次系统性能瓶颈的寻找过程》 的后续篇,该篇介绍了如何使用 JDK 自身提供的工具进行 JVM 调优将 TPS 由 2.5 提升到 20 (提升了 7 倍),并准确定位系统瓶颈:我们应用里静态对象不是太多、有大量的业务线程在频繁创建一些生命周期很长的临时对象,代码里有问题。那么问题来了,如何在海量业务代码里边准确定位这些性能代码?本文将介绍如何使用阿里开源工具 TProfiler 来定位这些性能代码,成功解决掉了 GC 过于频繁的性能瓶颈,并最终在上次优化的基础上将 TPS 再提升了4 倍,即提升到 100。

1. TProfiler 的下载安装

1.1. 下载

访问 TProfiler 的 GitHub 主页,点击 Clone or download 按钮的打开下载选项,点击该选项下的 Download ZIP 按钮将 TProfiler-master.zip 下载到本地。笔者上传了一份截至 20160920 最新 TProfiler-master.zip 到 CSDN 资源,读者朋友也可以去这里下载:http://download.csdn.net/detail/defonds/9635731

1.2. 安装

SSH 登录需要监控的远程服务器主机,为 TProfiler 新建安装路径:
mkdir /opt/tprofiler
本地将下载后的 TProfiler-master.zip 解压缩,将 dist 目录下的 profile.properties 以及 dist/lib 目录下的 tprofiler-1.0.1.jar ftp 上传到远程服务器 /opt/tprofiler 目录下。
最后将远程服务器 /opt/tprofiler 目录及其下所有文件的所有者改为启动 Weblogic 进程的用户及其所在用户组。

2. TProfiler 的配置部署

2.1. TProfiler 配置

编辑服务器 /opt/tprofiler/profile.properties 文件内容如下:
#log file name
logFileName = tprofiler.log
methodFileName = tmethod.log
samplerFileName = tsampler.log

#basic configuration items
startProfTime = 9:00:00
endProfTime = 23:00:00
eachProfUseTime = 5
eachProfIntervalTime = 50
samplerIntervalTime = 20
port = 30000
debugMode = false
needNanoTime = false
ignoreGetSetMethod = true

#file paths
logFilePath = ${user.home}/logs/${logFileName}
methodFilePath = ${user.home}/logs/${methodFileName}
samplerFilePath = ${user.home}/logs/${samplerFileName}

#include & excludes items
excludeClassLoader = org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader
includePackageStartsWith = com.caucho;com.defonds;com.fasterxml;com.sun.jersey;com.sun.jmx;org.apache;org.codehaus;org.jdbcdslog;org.mybatis;org.quartz;org.springframework
excludePackageStartsWith = com.taobao.sketch;org.apache.velocity;com.alibaba;com.taobao.forest.domain.dataobject
红色部分是我们修改后的内容,其它部分使用默认值。

2.2. Weblogic 启动参数配置

在 Weblogic JVM 启动参数里加入:
-javaagent:/opt/tprofiler/tprofiler-1.0.1.jar -Dprofile.properties=/opt/tprofiler/profile.properties
之后重启 Weblogic。

3. TProfiler 的远程操作

使用启动 Weblogic 进程的用户 SSH 远程登录正在进行压测的机器。

3.1. 查看 TProfiler 当前状态

java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
running
得到这个结果证明 TProfiler 正在进行采集工作。

3.2. 将 TProfiler 停止,以释放其占用的系统资源

随时关闭 TProfiler:
java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 stop
java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
stop
随时启动以继续采集:
java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 start
java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 status
running

3.3. 刷出数据

java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 30000 flushmethod
会将数据刷出到 ~/logs/ 目录下:
TProfiler的日志.png

4. TProfiler 对性能方法的采集

4.1. 普通方法、线程统计

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

4.2. top 统计

java -cp /opt/tprofiler/tprofiler-1.0.1.jar com.taobao.profile.analysis.ProfilerLogAnalysis ~/logs/tprofiler.log ~/logs/tmethod.log ~/logs/topmethod.log ~/logs/topobject.log
方法执行时间统计:这个非常非常重要,这个是 TProfiler 最最重要的 feature,是其能够傲视所有其他性能测试类(包括 jvm 性能测试类)软件的关键所在,我们将会不止一次地在关键的时候受益于 TProfiler 的这一非常有用的特性。
上述命令刷出的 topmethod.log 部分结果如下:
com/defonds/core/ppts/common/support/JsonUtils:object2jsonString:123 13519 154 2083584
com/caucho/hessian/client/HessianURLConnection:sendRequest:156 15894 130 2072565
com/defonds/rest/core/client/proxy/ResourceJsonInvocationHandler:invoke:39 8123 113 921340
com/defonds/core/ppts/cache/service/impl/MerBankCfgServiceImpl:selectMerBankCfgByParams:72 54213 15 799322
com/defonds/core/ppts/incomes/biz/sinopay/service/impl/SinoPayBankReturnServiceImpl4Json:updateOrderSuccess:792 2495 176 438542
com/defonds/core/ppts/common/support/framework/bean/Message:<init>:76 6219 26 163741
com/fasterxml/jackson/databind/ser/impl/IndexedListSerializer:serializeContents:107 51883 3 145556
com/defonds/core/ppts/cache/biz/cims/impl/AccountPrdAndBankCacheImpl:selectBasicProductCfg:144 16131 8 137029
格式说明:方法信息 执行次数 平均执行时间(单位:ms) 全部执行时间(单位:ms)

5. 性能方法的优化

根据 topmethod.log 统计结果,我们拿到了热点方法 top10:

热点方法 top10
方法名 被调用次数 平均执行时间(ms) 采样内总执行时间(ms)
com/defonds/core/ppts/common/support/JsonUtils:object2jsonString:123 13519 154 2083584
com/caucho/hessian/client/HessianURLConnection:sendRequest:156 15894 130 2072565
com/defonds/rest/core/client/proxy/ResourceJsonInvocationHandler:invoke:39 8123 113 921340
com/defonds/core/ppts/cache/service/impl/MerBankCfgServiceImpl:selectMerBankCfgByParams:72 54213 15 799322
com/defonds/core/ppts/incomes/biz/sinopay/service/impl/SinoPayBankReturnServiceImpl4Json:updateOrderSuccess:792 2495 176 438542
com/defonds/core/ppts/common/support/framework/bean/Message:<init>:76 6219 26 163741
com/fasterxml/jackson/databind/ser/impl/IndexedListSerializer:serializeContents:107 51883 3 145556
com/defonds/core/ppts/cache/biz/cims/impl/AccountPrdAndBankCacheImpl:selectBasicProductCfg:144 16131 8 137029
com/defonds/core/ppts/common/jms/retrieve/listener/DefaultMessageListener:handleMessage:64 2981 46 136180
com/fasterxml/jackson/databind/ser/BeanPropertyWriter:serializeAsField:573 53892 2 112553


这是压测时根据多次采样结果,拣选出的一次比较有代表性的一次。红色部分值得我们去重点关注并优化一下,因为极有可能就是应用瓶颈所在。这些代码要么是导致平均响应时间低下的一些点,要么是导致大量临时对象产生的一些点。
对于上篇博客中的结论,这些代码的调优原则是:临时对象能改成静态对象进行复用就改成公用对象否则要想方设法缩短其生命周期;高频访问代码提高响应速度。根据 jvm gc 日志发现很多 young gc 之后堆内存已用空间不仅下降反而上升至最大使用量导致 full gc,临时对象如果可以和其它线程复用的话改成静态对象以减少大量线程 local 对象的产生。
以排名第一的热点方法 com/defonds/core/ppts/common/support/JsonUtils:object2jsonString:123 为例,看看如何来进行调优。

 
  1. import org.codehaus.jackson.map.ObjectMapper;

  2. public static <T> String object2jsonString(T t) {

  3. try {

  4. ObjectMapper objectMapper = instanceObjectMapper();

  5. return objectMapper.writeValueAsString(t);

  6. } catch (JsonParseException e) {

  7. log.error(e.getMessage(), e);

  8. throw new SysException(e);

  9. } catch (JsonMappingException e) {

  10. log.error(e.getMessage(), e);

  11. throw new SysException(e);

  12. } catch (IOException e) {

  13. log.error(e.getMessage(), e);

  14. throw new SysException(e);

  15. }

  16. }

  17. public static ObjectMapper instanceObjectMapper() {

  18. JsonFactory jf = new JsonFactory();

  19. jf.configure(Feature.WRITE_NUMBERS_AS_STRINGS, true);

  20. return new ObjectMapper(jf);

  21. }


该热点方法的优化建议:
这个方法平均调用时间在 154ms,如果在低并发时可能比这要小得多。但是高并发时可能要等待 GC 的堆内存释放、GC 作业时对业务线程造成的暂停时间等因素影响,这个时间会被无限放大。

5.1. 临时对象改成静态对象

object2jsonString 方法的 objectMapper 对象,instanceObjectMapper 方法的 jf 对象;

5.2. json 处理由 jackson 改为 fastjson

jackson 和 spring 整合的很好,提供的功能点很多很强大。但是其性能未必靠得住。
比如我们原来用过谷歌的 Gson 进行 json 处理,某个大对象的 json 解析使用 gson 是 100 多秒,而换成 fastjson 解析后是 900 多毫秒。上百倍的性能差距呀,这还是在单用户操作、不能存在 CPU 和内存等资源限制及竞争的情况下拿到的数据。在此向贡献出 fastjson 的阿里人致敬~

5.3. 频繁 GC 的瓶颈已不复存在

针对 TProfiler 帮我们在海量业务代码中定位到的 top5 性能代码进行优化后,部署重新压测,50 个用户并发两个小时左右,我们拉了几次快照,上篇博客中定位的频繁 GC 的性能瓶颈已不复存在,TRT 也由上篇博客优化到的 2.5 下降到 0.5,TPS 基本能稳定在 100 个。问题圆满解决。

6. 需要注意的一些问题

6.1. TProfiler 端口号是否已被占用

为 TProfiler 选取端口号之前要先检测一下该端口号是否已被占用:
netstat -an | grep 30000

6.2. TProfiler 配置里 includePackageStartsWith 

一定要根据你自己的系统进行实际更改,不然就会遇到《TProfiler.log的内容为空 #33》的问题,截图如下:
TProfiler.log的内容为空.png

6.3. 几个命令配合使用

在压测的时候,结合使用 start、stop、flushmethod、ProfilerLogAnalysis topmethod 等几个命令,以拿到关键性的结果。如果能再结合 Weblogic、LoadRunner 的启动、停止,效果最佳。不然的话,如果 JVM 已经跑了很多天,拿到的数据可能不是你想要的,反而会误导你南辕北辙。

7. 后记

总体来讲,TProfiler 配置部署、远程操作、日志阅读都不太复杂,操作还是很简单的。但是其却是能够起到一针见血、立竿见影的效果,帮我们解决了 GC 过于频繁的性能瓶颈。
TProfiler 最重要的特性就是能够统计出你指定时间段内 JVM 的 topmethod,这些 topmethod 极有可能就是造成你 JVM 性能瓶颈的元凶。这是其他大多数 JVM 调优工具所不具备的,包括 JRockit Mission Control。JRokit 首席开发者 Marcus Hirt 在其私人博客《Low Overhead Method Profiling with Java Mission Control》下的评论中曾明确指出 JRMC 并不支持 TOP 方法的统计:
JRMC并不支持TOP方法的统计.png
最后再次向具备开源精神的阿里技术团队致敬~


微信公众号【Java技术江湖】一位阿里 Java 工程师的技术小站。(关注公众号后回复”Java“即可领取 Java基础、进阶、项目和架构师等免费学习资料,更有数据库、分布式、微服务等热门技术学习视频,内容丰富,兼顾原理和实践,另外也将赠送作者原创的Java学习指南、Java程序员面试指南等干货资源)

相关实践学习
通过性能测试PTS对云服务器ECS进行规格选择与性能压测
本文为您介绍如何利用性能测试PTS对云服务器ECS进行规格选择与性能压测。
相关文章
|
1月前
|
NoSQL Java Redis
秒杀抢购场景下实战JVM级别锁与分布式锁
在电商系统中,秒杀抢购活动是一种常见的营销手段。它通过设定极低的价格和有限的商品数量,吸引大量用户在特定时间点抢购,从而迅速增加销量、提升品牌曝光度和用户活跃度。然而,这种活动也对系统的性能和稳定性提出了极高的要求。特别是在秒杀开始的瞬间,系统需要处理海量的并发请求,同时确保数据的准确性和一致性。 为了解决这些问题,系统开发者们引入了锁机制。锁机制是一种用于控制对共享资源的并发访问的技术,它能够确保在同一时间只有一个进程或线程能够操作某个资源,从而避免数据不一致或冲突。在秒杀抢购场景下,锁机制显得尤为重要,它能够保证商品库存的扣减操作是原子性的,避免出现超卖或数据不一致的情况。
64 10
|
1月前
|
监控 架构师 Java
Java虚拟机调优的艺术:从入门到精通####
本文作为一篇深入浅出的技术指南,旨在为Java开发者揭示JVM调优的神秘面纱,通过剖析其背后的原理、分享实战经验与最佳实践,引领读者踏上从调优新手到高手的进阶之路。不同于传统的摘要概述,本文将以一场虚拟的对话形式,模拟一位经验丰富的架构师向初学者传授JVM调优的心法,激发学习兴趣,同时概括性地介绍文章将探讨的核心议题——性能监控、垃圾回收优化、内存管理及常见问题解决策略。 ####
|
2月前
|
监控 算法 Java
jvm-48-java 变更导致压测应用性能下降,如何分析定位原因?
【11月更文挑战第17天】当JVM相关变更导致压测应用性能下降时,可通过检查变更内容(如JVM参数、Java版本、代码变更)、收集性能监控数据(使用JVM监控工具、应用性能监控工具、系统资源监控)、分析垃圾回收情况(GC日志分析、内存泄漏检查)、分析线程和锁(线程状态分析、锁竞争分析)及分析代码执行路径(使用代码性能分析工具、代码审查)等步骤来定位和解决问题。
|
2月前
|
监控 Java 编译器
Java虚拟机调优指南####
本文深入探讨了Java虚拟机(JVM)调优的精髓,从内存管理、垃圾回收到性能监控等多个维度出发,为开发者提供了一系列实用的调优策略。通过优化配置与参数调整,旨在帮助读者提升Java应用的运行效率和稳定性,确保其在高并发、大数据量场景下依然能够保持高效运作。 ####
44 1
|
2月前
|
存储 算法 Java
JVM进阶调优系列(10)敢向stop the world喊卡的G1垃圾回收器 | 有必要讲透
本文详细介绍了G1垃圾回收器的背景、核心原理及其回收过程。G1,即Garbage First,旨在通过将堆内存划分为多个Region来实现低延时的垃圾回收,每个Region可以根据其垃圾回收的价值被优先回收。文章还探讨了G1的Young GC、Mixed GC以及Full GC的具体流程,并列出了G1回收器的核心参数配置,帮助读者更好地理解和优化G1的使用。
|
2月前
|
监控 Java 测试技术
Elasticsearch集群JVM调优垃圾回收器的选择
Elasticsearch集群JVM调优垃圾回收器的选择
75 1
|
2月前
|
Arthas 监控 Java
JVM进阶调优系列(9)大厂面试官:内存溢出几种?能否现场演示一下?| 面试就那点事
本文介绍了JVM内存溢出(OOM)的四种类型:堆内存、栈内存、元数据区和直接内存溢出。每种类型通过示例代码演示了如何触发OOM,并分析了其原因。文章还提供了如何使用JVM命令工具(如jmap、jhat、GCeasy、Arthas等)分析和定位内存溢出问题的方法。最后,强调了合理设置JVM参数和及时回收内存的重要性。
|
2月前
|
监控 Java 编译器
Java虚拟机调优实战指南####
本文深入探讨了Java虚拟机(JVM)的调优策略,旨在帮助开发者和系统管理员通过具体、实用的技巧提升Java应用的性能与稳定性。不同于传统摘要的概括性描述,本文摘要将直接列出五大核心调优要点,为读者提供快速预览: 1. **初始堆内存设置**:合理配置-Xms和-Xmx参数,避免频繁的内存分配与回收。 2. **垃圾收集器选择**:根据应用特性选择合适的GC策略,如G1 GC、ZGC等。 3. **线程优化**:调整线程栈大小及并发线程数,平衡资源利用率与响应速度。 4. **JIT编译器优化**:利用-XX:CompileThreshold等参数优化即时编译性能。 5. **监控与诊断工
|
2月前
|
存储 IDE Java
实战优化公司线上系统JVM:从基础到高级
【11月更文挑战第28天】Java虚拟机(JVM)是Java语言的核心组件,它使得Java程序能够实现“一次编写,到处运行”的跨平台特性。在现代应用程序中,JVM的性能和稳定性直接影响到系统的整体表现。本文将深入探讨JVM的基础知识、基本特点、定义、发展历史、主要概念、调试工具、内存管理、垃圾回收、性能调优等方面,并提供一个实际的问题demo,使用IntelliJ IDEA工具进行调试演示。
54 0
|
2月前
|
缓存 Prometheus 监控
Elasticsearch集群JVM调优设置合适的堆内存大小
Elasticsearch集群JVM调优设置合适的堆内存大小
515 1