使用Arthas分析Java接口耗时情况

1,701 阅读3分钟

什么是Arthas

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

官网文档:arthas.aliyun.com/doc/

GitHub地址:github.com/alibaba/art…

码云地址:arthas.gitee.io/

  • Arthas安装

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

wget https://arthas.aliyun.com/arthas-boot.jar
  • 启动对应的jar
java -jar arthas-boot.jar 

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

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

如图所示:

image.png

原因是因为要加上对应的线程id,运行对应的Java程序

查看运行的Java程序:

ps -aux|grep java

可以找到xxxx.jar对应的pid是22676,所以现在再执行

java -jar arthas-boot.jar 22676

trace命令的使用

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

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

trace com.leelen.cloud.app.lbl.service.deviceUpgrade.impl.DeviceUpgradeServiceImpl upgradeDeviceConfirm -n 1 --skipJDKMethod false

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

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

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



`---ts=2023-12-23 11:21:03;thread_name=http-nio-9131-exec-894;id=492;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@56193c7d
    `---[2214.568827ms] com.leelen.cloud.app.lbl.service.deviceUpgrade.impl.DeviceUpgradeServiceImpl:upgradeDeviceConfirm()
        +---[0.19% 4.191319ms ] com.leelen.cloud.app.lbl.utils.TokenManageUtils:getTokenInfoByRequest() #161
        +---[0.00% 0.003293ms ] com.leelen.cloud.dto.generic.TokenInfo:getOwnerId() #162
        +---[0.00% 0.003034ms ] com.leelen.cloud.dto.generic.TokenInfo:getClientId() #163
        +---[0.00% 0.003865ms ] com.leelen.cloud.dto.communitybase.deviceUpgrade.UpgradeModuleConfirmReqDTO:setOwnerId() #165
        +---[0.00% 0.003653ms ] com.leelen.cloud.dto.communitybase.deviceUpgrade.UpgradeModuleConfirmReqDTO:setAppClientId() #166
        +---[0.00% 0.003423ms ] com.leelen.cloud.dto.communitybase.deviceUpgrade.UpgradeModuleConfirmReqDTO:setSeq() #167
        +---[0.00% 0.002136ms ] org.slf4j.Logger:isInfoEnabled() #168
        +---[0.00% 0.002284ms ] com.leelen.cloud.dto.communitybase.deviceUpgrade.UpgradeModuleConfirmReqDTO:getGroupId() #169
        +---[0.00% 0.031633ms ] org.slf4j.Logger:info() #169
        +---[99.80% 2210.161538ms ] com.leelen.cloud.app.lbl.service.feign.IotGateWayFeignService:upgradeDeviceConfirm() #171
        +---[0.00% 0.004524ms ] org.slf4j.Logger:isInfoEnabled() #172
        +---[0.00% 0.002891ms ] com.leelen.cloud.dto.communitybase.deviceUpgrade.UpgradeModuleConfirmReqDTO:getGroupId() #173
        `---[0.00% 0.066519ms ] org.slf4j.Logger:info() #173

image.png

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

trace com.leelen.cloud.app.lbl.service.deviceUpgrade.impl.DeviceUpgradeServiceImpl upgradeDeviceConfirm '#cost > 100' -n 100

遇到Arthas启动不了

启动arthas之后, 选择要attach的进程之后控制台报错内容如下:The telnet port 3658 is used by process 29877 instead of target process 7067

[INFO] arthas home: /root/.arthas/lib/3.5.0/arthas
[ERROR] The telnet port 3658 is used by process 27820 instead of target process 24012, you will connect to an unexpected process.
[ERROR] 1. Try to restart arthas-boot, select process 27820, shutdown it first with running the 'stop' command.
[ERROR] 2. Or try to stop the existing arthas instance: java -jar arthas-client.jar 127.0.0.1 3658 -c "stop"
[ERROR] 3. Or try to use different telnet port, for example: java -jar arthas-boot.jar --telnet-port 9998 --http-port -1
[root@sian-application-dev tools]# java -jar arthas-boot.jar

这个一般出现在远程到服务器上之后,没有正常退出arthas监听进程,然后远程ssh过期了,需要重新登录服务器。然后再次attach与上一次不同的进程之后就会出现这个错误。

-解决办法:

  • 再次运行arthas

java -jar arthas-boot.jar

根据错误提示找到对应的进程, 如上面日志提示进程是27820, 则启动arthas之后,重新选择这个进程attach,成功之后执行stop命令,然后再正常退出arthas即可,再次启动attach其它进程即可。

image.png

  • 输入进程序号,选择对应的进程

例如数据进程前方的序号:1

  • 停止arthas

stop

image.png