使用Arthas分析Java线上接口耗时
  NrKhGdPqPgIO 2023年12月02日 15 0


使用Arthas分析Java线上接口耗时_开发语言

项目场景

在生产环境,经常会遇到需要排查一个接口里哪里比较耗时,按照以前的做法,可能是通过打印logger,然后打补丁,重新部署

@Test
 void testNeedTime() {
     long startTime = System.currentTimeMillis();

     AtomicInteger num1 = new AtomicInteger(1);
     IntStream.range(1,10).forEach(i-> num1.incrementAndGet());
     long endTime1 = System.currentTimeMillis();
     log.info("耗时: {}" , endTime1 - startTime);

     AtomicInteger num2 = new AtomicInteger(1);
     IntStream.range(1,100).forEach(i-> num2.incrementAndGet());
     long endTime2 = System.currentTimeMillis();
     log.info("耗时: {}" , endTime2 -  endTime1 );

 }

如果是可以频繁更新的项目,或者是构建比较容易的项目,倒还好,如果项目不能频繁更新或者是部署过程比较麻烦,通过打补丁的方式就有点麻烦了,所以需要有款平台可以支持不打补丁就可以定时问题的分析工具,阿里开源的Arthas就是一款很不错的线上问题分析神器


什么是Arthas?

Arthas 是一款线上监控诊断平台,可以实时查看应用 load、内存、gc、线程的状态信息,可以在不修改代码的情况,定时问题,分析接口耗时、传参、异常等情况,提高线上问题排查效率


Arthas安装

先将对应的arthas程序下载到本地,可以使用wget命令,也可以使用官网介绍的curl访问对应链接

wget https://arthas.aliyun.com/arthas-boot.jar

然后安装文档,启动对应的jar

java -jar arthas-boot.jar --repo-mirror aliyun --use-http

发现启动时候报错了,报错如下所示:

Can not find java process. Try to run `jps` command lists the instrumented Java HotSpot VMs on the target system.
Please select an available pid.

如图所示:

使用Arthas分析Java线上接口耗时_java_02


原因是因为要加上对应的线程id,但是我们没有运行对应的Java程序,所以可以去官网下载一个Java程序的例子math-game.jar

使用Arthas分析Java线上接口耗时_开发语言_03


然后先java -jar math-game.jar,运行对应的Java程序

查看运行的Java程序:

ps -aux|grep java

可以找到math-game.jar对应的pid是2266,所以现在再执行

java -jar /usr/local/arthas/arthas-boot.jar 2266

使用Arthas分析Java线上接口耗时_Java_04


trace命令的使用

下面给出例子,分析一个接口加载慢问题

trace命令可以用于分析哪里耗时比较长,比如我们要分析一个类OrderServiceImpl中的listOrder方法,就可以使用命令

trace com.sample.order.orderServiceImpl listOrder -n 1  --skipJDKMethod
false

-n是指定捕捉结果的次数,如果接口调用次数比较多,就可以适当加捕捉结果次数

--skipJDKMethod false是打开jdk方法的打印,其实一般情况都可以不加,因为jdk方法相对比较稳定

如何等接口调用,也可以手动调用接口,就可以打印出如下的监控信息,具体那里加载慢都可以定位到

--[100.00% 3434.755668ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[100.00% 3434.620187ms ] cn.test.server.business.VisitorBusiness:getStaffList()
                +---[0.00% 0.045431ms ] cn.test.client.dto.StaffListReqDto:getComId() #188
                +---[0.00% 0.019135ms ] cn.core.common.utils.CoreUtils:isEmpty() #188
                +---[0.00% 0.021816ms ] cn.hutool.core.date.DateUtil:timer() #192
                +---[0.00% 0.019987ms ] com.google.common.base.Splitter:on() #194
                +---[0.00% 0.005501ms ] cn.test.client.dto.StaffListReqDto:getComId() #194
                +---[0.00% 0.026292ms ] com.google.common.base.Splitter:splitToList() #194
                +---[0.00% 0.131507ms ] cn.hutool.core.convert.Convert:toInt() #195
                +---[0.34% 11.668407ms ] cn.core.user.client.querier.SchoolQuerierService:findBySchoolId() #198
                +---[0.00% 0.024199ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #203
                +---[0.02% 0.535107ms ] org.slf4j.Logger:info() #203
                +---[2.66% 91.504718ms ] cn.core.user.client.querier.RelationQuerierService:queryUserByIdsAndRoleType() #206
                +---[0.00% 0.019208ms ] com.google.common.collect.Lists:newArrayList() #206
                +---[0.00% 0.01107ms ] cn.core.common.utils.CoreUtils:isEmpty() #207
                +---[0.00% 0.013517ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #211
                +---[0.02% 0.532242ms ] org.slf4j.Logger:info() #211
                +---[0.00% 0.016216ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #218
                +---[0.01% 0.435469ms ] org.slf4j.Logger:info() #218
                +---[0.00% 0.009024ms ] cn.test.client.dto.StaffListReqDto:getComId() #221
                +---[0.53% 18.336268ms ]cn.test.persistence.dao.LogMapper:listStaffSyncRecordByComId() #221
                +---[0.00% 0.009043ms ] com.google.common.collect.Lists:newArrayList() #221
                +---[0.00% 0.019237ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #223
                +---[0.01% 0.279834ms ] org.slf4j.Logger:info() #223
                +---[0.00% 0.014057ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #227
                +---[0.01% 0.270155ms ] org.slf4j.Logger:info() #227
                +---[0.00% 0.006338ms ] com.google.common.collect.Lists:newArrayList() #231
                +---[0.00% 0.019707ms ] cn.hutool.core.date.TimeInterval:intervalRestart() #263
                +---[0.02% 0.548875ms ] org.slf4j.Logger:info() #263
                `---[0.00% 0.027475ms ] cn.test.client.dto.Result:success() #265

如果要打印接口里耗时大于多少毫秒,就可以使用命令,如下是筛选大于100ms的

trace com.sample.order.orderServiceImpl listOrder '#cost > 100' -n 1


【版权声明】本文内容来自摩杜云社区用户原创、第三方投稿、转载,内容版权归原作者所有。本网站的目的在于传递更多信息,不拥有版权,亦不承担相应法律责任。如果您发现本社区中有涉嫌抄袭的内容,欢迎发送邮件进行举报,并提供相关证据,一经查实,本社区将立刻删除涉嫌侵权内容,举报邮箱: cloudbbs@moduyun.com

  1. 分享:
最后一次编辑于 2023年12月02日 0

暂无评论

推荐阅读
NrKhGdPqPgIO