Java 性能瓶颈分析工具 你知道几个?

本文介绍了常用的性能分析工具和故障排查工具,希望可以帮助开发人员在排查性能问题的时候快速定位到性瓶颈。每个工具都有其优势与劣势,只有更好了解问题所出现的场景,理清解决问题的思路,才能最大化的发挥工具的价值。


0. Introduction

Java 性能优化分为很多个方面,如系统优化、算法优化、代码优化等。代码优化是指开发人员在研发、测试过程中使用性能瓶颈分析工具快速定位出由于编码存在的性能瓶颈问题并持续进行优化。一种很常见的场景是测试同学在对服务进行压测时,无论怎么增加并发应用的 TPS 一直保持在某个值进行左右波动,这个时候要怎么排查呢。为了可以准确获得运行过程中程序的性能数据,性能调优人员和开发者需要使用性能分析(profiling)辅助工具从全局视角来查看系统的运行状况。本文主要介绍通过熟练掌握 JMC、Tprofiler、JProfiler 等各种性能瓶颈分析工具,进而提高定位性能瓶颈、系统故障排查能力。

1. Java Mission Control

JMC(Java 任务控制)是 Java 7u40 新增加的性能监控工具。目前,Oracle Java 官方在今年 5 月份已经公布 Java Mission Control(JMC)的源代码已正式开源,此举得到了 Java 开发社区的高度赞赏。

JMC 源码地址: JMC source code

JMC 工具主要由三个组件构成:Java 进程浏览器、JMX 控制台和 Java Flight 记录器等。

Java 进程浏览器能够利用 Java 自带的 JDP 协议自动发现本地或者远程正在使用的 Java 进程;

JMX 控制台通过 JMX 接口管理监控 JDK,它能够查看堆内存使用情况、CPU 负载等;

Java Flight Recorder 是一个内置在 JDK 中的监测和事件收集框架。收集的事件包括:磁盘 IO、GC、线程 sleep、线程 wait、Socket read/write 等。

下图显示了 JMC 启动后当前机器正在运行中的所有 Java 进程,选择一个进程进行性能监控。

如果使用的操作系统是 Mac 并且 JDK 版本为 1.8,启动 JMC 之后可能会发现操作界面被冷冻住了你没办法进行任何操作。产生这种现象的原因是 JDK 在升级过程中存在一个bug,具体解决方案可以参考:

Jdk1.8 bug

1.1 JFR 内存视图

JFR 模块包含一般信息、内存、代码、线程、IO、系统、事件等视图。其中,JFR 内存视图收集的信息非常丰富,可以获得内测使用量、GC 配置、GC 时间、对象统计时间等统计信息。下图展示了当前 JVM 进程 GC 时间的统计信息。

1.2 JFR 代码视图

JFR 代码视图可以很容易统计出所有 Java 包占 JVM 进程所有方法调用的总时长。该视图很方便查看热点类、热点方法和热点包的调用次数、所占比例等。JFR 还提供了 I/O 视图、线程视图、系统视图从不同角度更好分析当前进程运行情况。

1.3 启动 JFR

Java 飞行记录器(JFR)是一种用于收集关于正在运行的 Java 应用程序的诊断和分析数据的工具。它集成到 Java 虚拟机(JVM)中,几乎不会造成性能开销,因此即使在负载非常大的生产环境中也可以使用它。

  • 首先,JVM 进程开启 JFR 功能需要在 JVM 启动参数(Jvm start flags)中增加两个参数
-XX:+UnlockCommercialFeatures -XX:+FlightRecorder 

默认情况下,JFR 在 JVM 中是禁用的。要启用 JFR,必须使用 - XX:+FlightRecorder 选项启动 Java 应用程序。因为 JFR 是一个商业特性,仅在基于 Java 平台、标准版(Oracle Java SE Advanced 和 Oracle Java SE Suite)的商业包中可用,所以您还必须使用 - XX:+UnlockCommercialFeatures 选项启用商业特性。

当然,也可以配置 JMC 进行远程监控,在启动 Java 程序时加上如下参数:

-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 

允许其它机器监控该程序,必须指定 -Djava.rmi.server.hostname=,如果不指定该配置,那么就只能在本机监控该程序。

控制监控的授权(让特定的用户才能连接 JMX 服务),需要设置

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

如果设置为 false 则不需要授权。

授权需要指定两个文件:jmxremote.password 和 jmxremote.access,password 文件主要是配置用户名和密码。

  • 其次,选中需要进行性能分析的进程,点击右键选择开启飞行记录器:

1.4 JFR 事件

JFR 记录并保存事件流,JMC 提供不同的视图来分析这些事件,但是 JFR 事件面板(如上图所示)才是分析事件最有效的途径。点击事件,展开堆栈跟踪。

从图中可以看出,在 2 分钟内发生了 4403 次 Hotspot JVM 事件和 161 次 Java Runtime 事件。应用程序有多个线程共消耗 73 毫秒向套接字内写数据(Socket Write);应用程序中多个线程共消耗 120 秒从套接字读取数据(Socket Read)。这看起来并不正常,通过查看这些事件的处理记录可以发现,由多个线程使用阻塞式 I/O 读取请求。这些管理请求的时间间隔通常很长,但这些线程却在 read() 方法内被阻塞,所以导致这些线程读取数据时消耗了过多的时间。

JFR 的事件就如黑匣子一般,通过收集的这些事件的详细信息能够更加深入了解程序的内部运行过程,这是很多其他工具所不具备的。

1.5 实际案例

API Gateway 是一种高并发、高流量的系统,它的主要功能是用于给第三方合作伙伴提供数据与服务的能力。因此,API Gateway 对于处理用户请求的完整链路中每个环节的性能损耗都会非常敏感。

最近,在升级网关的核心功能模块之后与测试同学一起合作对网关的某些 API 接口进行性能压力测试,利用压测机 Jmeter 模拟多用户并发请求。但不管怎么增加并发数,每分钟的请求总量稳定保持在 4 万/min,TPS 也一直在 650 左右波动,而且所有服务器的 CPU、内存、网络、IO 占用率均不高。

针对这种情况,我们首先排除了业务方的性能问题,因此直接对业务方(2 核 8G)发起并发请求,TPS 都可以达到 800 左右的并发数。其次,我们也排除了接入层 SLB、OpenResty 的问题,因为网关未升级核心功能情况下单台网关的 TPS 很容易达到 4000 左右。

因此,根据以上分析基本可以确定性能瓶颈出在网关处理请求的过程中。

在网关的 JVM 启动参数中增加 JFR 启动参数:

-XX:+UnlockCommercialFeatures -XX:+FlightRecorder 

使用 JFR 的事件视图点击堆栈跟踪,就可以查看到代码调用链,看到自己的业务代码,从而定位到最耗时的代码位置。

下图很清楚展示了来自客户端每个请求主要的事件都耗费在调用 Redis 读取 API 元信息,每一次读取源信息都需要进行序列化与反序列化,导致平均响应时间增加网关处理请求时间加长,因此 TPS 下降并一直稳定在某个值。解决方案 API 元信息尽可能缓存到本地 JVM 内存,优先从本地内存读取数据减少访问 Redis 频次。

当然系统 TPS 上不去的原因也不能仅仅从单一维度分析,要综合起来多维度进行分析,如网络带宽、连接池、Java 内存管理、HTTP 通信机制、业务逻辑、系统架构(缓存、数据库等)等等。

2. Tprofiler

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

TProfiler 在 JVM 启动时把时间采集程序注入到字节码中,整个过程无需修改应用源码。运行时会把数据写到日志文件,一般情况下每小时输出的日志小于 50M。目前 TProfiler 已应用于淘宝的核心 Java 前端系统,部署后低峰期对应用响应时间影响 20% 高峰期对吞吐量大约有 30% 的降低。

2.1 配置部署

  • 安装 TProfiler
    直接下载完整安装包或者下载源码运行 package.bat 脚本或者执行 mvn assembly:assembly命令生成 tprofiler.jar 即可。

  • 配置 profile.properties

profile.properties 作为 tprofiler.jar 的配置文件,可以根据实际情况进行调整。

#log file name 
logFileName = tprofiler.log 
methodFileName = tmethod.log 
samplerFileName = tsampler.log 
#basic configuration items 
startProfTime = 19:00:00 #开始进行profile的时间 
endProfTime = 23:00:00 #结束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 启动参数中添加,然后重启应用。

-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 #远程查看状态操作 
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 #远程刷出方法数据 

2.2 TProfiler 性能方法的采集

TProfiler 能够生成日志:tmethod.log、tprofiler.log、tsampler.log。

普通方法、线程信息统计
执行如下命令,会生成 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 文件格式说明:

方法信息 采样过程中方法出现次数 
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 文件格式说明:

线程信息 采样过程中线程出现次数 
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 热点方法、热点对象信息统计

执行如下命令,生成 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 文件格式说明:

方法信息 执行次数 平均执行时间 全部执行时间 
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 文件格式说明:

方法信息 执行次数 平均执行时间 全部执行时间 
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 

这是压测多次时随机挑选的一次结果。热点方法和热点代码尤其值得我们关注,因此及其有可能是代码瓶颈所在。这些热点代码一般要么是平均响应时间高一些,要是产生的临时对象会多一些。

3. Jprofiler

JProfiler 是由 ej-technologies 公司开发的一款性能瓶颈分析工具。它是一款优秀的商业软件,功能非常丰富,因此具备一些免费软件所不具备的功能。Jprofiler 提供的主要功能有内存视图、CPU 视图、线程视图、堆遍历器(Heap Walker)等。

3.1 Jprofiler 使用

CPU 视图可以查看各个函数的 CPU 占用时间。Hot Spots 显示消耗时间最多的方法的列表,它不仅给出了单个函数的 CPU 使用时间和方法调用次数,同时还能显示函数调用堆栈信息,方便定位问题。

在线程视图可以统计并查询当前 JVM 所有线程的运行状态,线程持有锁的状态并且可 dump 线程。

4. Arthas

Arthas 是阿里最近刚刚开源的 Java 生成环境诊断工具。

Arthas 支持在 Linux/Unix/Mac 等平台上进行一键安装,现在处于试用于反馈阶段,感兴趣的同学可以自己研究试用。

5.Conclusion

本文介绍了常用的性能分析工具和故障排查工具,希望可以帮助开发人员在排查性能问题的时候快速定位到性瓶颈。每个工具都有其优势与劣势,只有更好了解问题所出现的场景,理清解决问题的思路,才能最大化的发挥工具的价值。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 159,117评论 4 362
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,328评论 1 293
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,839评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 44,007评论 0 206
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,384评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,629评论 1 219
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,880评论 2 313
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,593评论 0 198
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,313评论 1 243
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,575评论 2 246
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,066评论 1 260
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,392评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,052评论 3 236
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,082评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,844评论 0 195
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,662评论 2 274
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,575评论 2 270

推荐阅读更多精彩内容