背景说明

项目上某个接口响应时间过长，需要查看方法耗时情况进行优化

安装配置

• 访问下载页进行下载：下载 | arthas

• 调整文件位置进行解压缩

- 查看arthas帮助命令（非必须，官网文档更详细）

C:\tools\arthas\4.0.1\bin>java -jar arthas-boot.jar -h
[INFO] JAVA_HOME: C:\Program Files\Java\jre-1.8
[INFO] arthas-boot version: 4.0.1
Usage: arthas-boot [--use-http] [--repo-mirror <value>] [--stat-url <value>][--select <value>] [--app-name <value>] [--tunnel-server <value>][--height <value>] [--username <value>] [--agent-id <value>] [--width<value>] [--password <value>] [-v] [--target-ip <value>] [--arthas-home<value>] [--telnet-port <value>] [-h] [--http-port <value>] [--versions][-c <value>] [--use-version <value>] [--attach-only] [-f <value>][--session-timeout <value>] [--disabled-commands <value>] [pid]Bootstrap ArthasNOTE: Arthas 4 supports JDK 8+. If you need to diagnose applications running on
JDK 6/7, you can use Arthas 3.EXAMPLES:java -jar arthas-boot.jar <pid>java -jar arthas-boot.jar --telnet-port 9999 --http-port -1java -jar arthas-boot.jar --username admin --password <password>java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
--app-name demoappjava -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
--agent-id bvDOe8XbTM2pQWjF4cfwjava -jar arthas-boot.jar --stat-url 'http://192.168.10.11:8080/api/stat'java -jar arthas-boot.jar -c 'sysprop; thread' <pid>java -jar arthas-boot.jar -f batch.as <pid>java -jar arthas-boot.jar --use-version 4.0.1java -jar arthas-boot.jar --versionsjava -jar arthas-boot.jar --select math-gamejava -jar arthas-boot.jar --session-timeout 3600java -jar arthas-boot.jar --attach-onlyjava -jar arthas-boot.jar --disabled-commands stop,dumpjava -jar arthas-boot.jar --repo-mirror aliyun --use-http
WIKI:https://arthas.aliyun.com/docOptions and Arguments:--use-http                    Enforce use http to download, default usehttps--repo-mirror <value>         Use special remote repository mirror, value iscenter/aliyun or http repo url.--stat-url <value>            The report stat url--select <value>              select target process by classname orJARfilename--app-name <value>            The app name--tunnel-server <value>       The tunnel server url--height <value>              arthas-client terminal height--username <value>            The username--agent-id <value>            The agent id register to tunnel server--width <value>               arthas-client terminal width--password <value>            The password-v,--verbose                     Verbose, print debug info.--target-ip <value>           The target jvm listen ip, default 127.0.0.1--arthas-home <value>         The arthas home--telnet-port <value>         The target jvm listen telnet port, default3658-h,--help                        Print usage--http-port <value>           The target jvm listen http port, default 8563--versions                    List local and remote arthas versions-c,--command <value>             Command to execute, multiple commandsseparated by ;--use-version <value>         Use special version arthas--attach-only                 Attach target process only, do not connect-f,--batch-file <value>          The batch file to execute--session-timeout <value>     The session timeout seconds, default 1800(30min)--disabled-commands <value>   disable some commands<pid>

• 启动arthas

进入arthas-boot所在目录

C:\tools\arthas\4.0.1\bin>java -jar arthas-boot.jar
[INFO] JAVA_HOME: C:\Program Files\Java\jre-1.8
[INFO] arthas-boot version: 4.0.1
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 3296 org.jetbrains.idea.maven.server.RemoteMavenServer36[2]: 20068 org.jetbrains.idea.maven.server.indexer.MavenServerIndexerMain[3]: 8004 org.jetbrains.jps.cmdline.Launcher[4]: 28632

备注

在linux服务器上也可以直接执行以下命令下载arthas-boot，使用方式是一样的

curl -O https://arthas.aliyun.com/arthas-boot.jar

测试arthas相关命令

在实际的开发过程中，比较常用的命令有trace以及watch

trace

• 启动测试程序，代码如下

ArthasController

package com.learn.demo.api.controller;import com.learn.demo.app.service.ArthasTestService;
import com.learn.demo.config.SwaggerTags;
import io.swagger.annotations.Api;
import io.swagger.annotations.ApiOperation;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;/*** @author PC*/
@Api(SwaggerTags.ARTHAS)
@RestController("arthasController.v1")
@RequestMapping(value = "/v1/arthas")
public class ArthasController {private final ArthasTestService arthasTestService;@Autowiredpublic ArthasController(ArthasTestService arthasTestService) {this.arthasTestService = arthasTestService;}@ApiOperation(value = "trace")@GetMapping(value = "/trace")public void testTrace() {arthasTestService.testTrace();}
}

ArthasTestServiceImpl

package com.learn.demo.app.service.impl;import com.learn.demo.app.service.ArthasTestService;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;/*** @author PC* @description arthas命令测试*/
@Service
public class ArthasTestServiceImpl implements ArthasTestService {private final static Logger logger = LoggerFactory.getLogger(ArthasTestServiceImpl.class);@Overridepublic void testTrace() {try {this.sleep2Sec();this.sleep3Sec();this.sleep5Sec();} catch (InterruptedException interruptedException) {logger.error("error:", interruptedException);}}private void sleep5Sec() throws InterruptedException {this.sleep2Sec();this.sleep3Sec();}private void sleep3Sec() throws InterruptedException {Thread.sleep(3000);}private void sleep2Sec() throws InterruptedException {Thread.sleep(2000);}
}

• 启动arthas

C:\tools\arthas\4.0.1\bin>java -jar arthas-boot.jar
[INFO] JAVA_HOME: C:\Program Files\Java\jre-1.8
[INFO] arthas-boot version: 4.0.1
[INFO] Process 29788 already using port 3658
[INFO] Process 29788 already using port 8563
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 29788 com.learn.demo.DemoApplication[2]: 3296 org.jetbrains.idea.maven.server.RemoteMavenServer36[3]: 20068 org.jetbrains.idea.maven.server.indexer.MavenServerIndexerMain[4]: 8004 org.jetbrains.jps.cmdline.Launcher[5]: 28632

• 选择服务

1
[INFO] arthas home: C:\tools\arthas\4.0.1\bin
[INFO] The target process already listen port 3658, skip attach.
[INFO] arthas-client connect 127.0.0.1 3658,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---./  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'wiki       https://arthas.aliyun.com/doc
tutorials  https://arthas.aliyun.com/doc/arthas-tutorials.html
version    4.0.1
main_class
pid        29788
time       2024-09-26 17:04:32.494

• 监听ArthasTestServiceImpl

[arthas@29788]$ trace com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 63 ms, listenerId: 1

• 访问接口，查看结果

`---ts=2024-09-26 17:16:43.672;thread_name=http-nio-8090-exec-2;id=35;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10030.9174ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[20.05% 2010.9733ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19+---[30.04% 3012.9335ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20`---[49.91% 5006.6693ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21

从以上结果可以看到，虽然sleep5Sec中有两个方法，但是并没有再往下跟踪，如果还想往下跟踪，可以使用-E搭配正则表达式匹配多个类，如下

[arthas@29788]$  trace -E com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace|sleep5Sec
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 2) cost in 36 ms, listenerId: 4
`---ts=2024-09-26 17:22:51.887;thread_name=http-nio-8090-exec-6;id=39;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10049.2604ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[20.01% 2011.2037ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19+---[29.96% 3010.5075ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20`---[50.03% 5027.4925ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21`---[100.00% 5027.4495ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec()+---[40.05% 2013.6029ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #29`---[59.94% 3013.699ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #30

还可以通过以下命令匹配所有方法（实际使用中不推荐）

[arthas@29788]$  trace -E com.learn.demo.app.service.impl.ArthasTestServiceImpl ^.*$
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 5) cost in 36 ms, listenerId: 6
`---ts=2024-09-26 17:26:02.369;thread_name=http-nio-8090-exec-9;id=42;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10030.386ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[20.04% 2010.014ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19|   `---[100.00% 2009.9902ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()+---[29.99% 3008.4957ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20|   `---[100.00% 3008.4593ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()`---[49.97% 5011.8321ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21`---[100.00% 5011.8071ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec()+---[40.01% 2005.0631ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #29|   `---[100.00% 2005.0008ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()`---[59.99% 3006.7124ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #30`---[100.00% 3006.688ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()

如果想要包含jdk的方法调用，可以使用--skipJDKMethod false

[arthas@29788]$ trace -E com.learn.demo.app.service.impl.ArthasTestServiceImpl ^.*$  --skipJDKMethod false
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 5) cost in 58 ms, listenerId: 8
`---ts=2024-09-26 17:31:33.874;thread_name=http-nio-8090-exec-1;id=34;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10021.9275ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[19.96% 2000.6579ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19|   `---[100.00% 2000.6237ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()|       `---[100.00% 2000.5922ms ] java.lang.Thread:sleep() #38+---[30.00% 3006.6054ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20|   `---[99.99% 3006.4251ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()|       `---[100.00% 3006.3974ms ] java.lang.Thread:sleep() #34`---[50.04% 5014.4843ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21`---[100.00% 5014.4558ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec()+---[40.09% 2010.5047ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #29|   `---[100.00% 2010.4748ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()|       `---[100.00% 2010.4551ms ] java.lang.Thread:sleep() #38`---[59.91% 3003.9176ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #30`---[100.00% 3003.8823ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()`---[100.00% 3003.8513ms ] java.lang.Thread:sleep() #34

如果想要捕获到n次就退出跟踪，可以使用-n，例如-n指定为1(默认为100),访问一次后就不再跟踪

[arthas@29788]$ trace -E com.learn.demo.app.service.impl.ArthasTestServiceImpl ^.*$  -n 1 --skipJDKMethod false
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 5) cost in 41 ms, listenerId: 9
`---ts=2024-09-26 17:38:15.346;thread_name=http-nio-8090-exec-3;id=36;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10022.2006ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[20.02% 2006.7205ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19|   `---[100.00% 2006.7072ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()|       `---[100.00% 2006.6909ms ] java.lang.Thread:sleep() #38+---[30.03% 3009.647ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20|   `---[100.00% 3009.625ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()|       `---[100.00% 3009.5833ms ] java.lang.Thread:sleep() #34`---[49.95% 5005.7963ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21`---[100.00% 5005.7747ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec()+---[40.05% 2004.8723ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #29|   `---[100.00% 2004.857ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec()|       `---[100.00% 2004.8452ms ] java.lang.Thread:sleep() #38`---[59.95% 3000.8796ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #30`---[100.00% 3000.8322ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec()`---[100.00% 3000.8175ms ] java.lang.Thread:sleep() #34Command execution times exceed limit: 1, so command will exit. You can set it with -n option.
[arthas@29788]$

在实际的使用过程中，我们可能并不需要每次都捕获，只需要捕获超过一定时间的记录，那么可以使用#cost命令

trace com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace -n 1 --skipJDKMethod false '#cost<8000'

访问接口，发现并没有记录

但是将,就会有记录了

trace com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace -n 1 --skipJDKMethod false '#cost>8000'

执行结果如下，命令换行会有错位，不用理会

000'has@29788]$ trace -E com.learn.demo.app.service.impl.ArthasTestServiceImpl ^.*$ -n 1 --skipJDKMethod false '#cost<8
<8000's@29788]$ trace com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace -n 1 --skipJDKMethod false '#cost
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 27 ms, listenerId: 13
>8000's@29788]$ trace com.learn.demo.app.service.impl.ArthasTestServiceImpl testTrace -n 1 --skipJDKMethod false '#cost
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 27 ms, listenerId: 14
`---ts=2024-09-26 17:48:23.872;thread_name=http-nio-8090-exec-2;id=35;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@60aec68a`---[10026.9622ms] com.learn.demo.app.service.impl.ArthasTestServiceImpl:testTrace()+---[20.07% 2011.962ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep2Sec() #19+---[29.96% 3004.3291ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep3Sec() #20`---[49.97% 5010.3703ms ] com.learn.demo.app.service.impl.ArthasTestServiceImpl:sleep5Sec() #21Command execution times exceed limit: 1, so command will exit. You can set it with -n option.
[arthas@29788]$

 watch

• 编写测试程序

ArthasController

@ApiOperation(value = "watch")
@PostMapping(value = "/watch")
public Map<String, Object> testWatch(@RequestBody List<Object> sourceList) {return arthasTestService.testWatch(sourceList);
}

ArthasTestServiceImpl

@Override
public Map<String, Object> testWatch(List<Object> argList) {if (CollectionUtils.isEmpty(argList)) {return new HashMap<>(0);}return argList.stream().filter(Objects::nonNull).collect(Collectors.toMap(Object::toString, Function.identity()));
}

• 常用命令

watch com.learn.demo.app.service.impl.ArthasTestServiceImpl testWatch '{params,returnObj,throwExp}'  -n 5  -x 3

• 参数说明：
  • {params,returnObj,throwExp}为 ognl 表达式，表示返回的三个参数分别是入参，返回结果、异常信息
  • -x 3表示出结果的属性遍历深度，默认为 1，最大值是 4
  • 默认参数为-f，表示在函数结束之后(正常返回和异常返回)观察

官网参数说明如下

• 访问接口测试

[arthas@9308]$ watch com.learn.demo.app.service.impl.ArthasTestServiceImpl testWatch '{params,returnObj,throwExp}'  -n 5  -x 3
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 28 ms, listenerId: 4
method=com.learn.demo.app.service.impl.ArthasTestServiceImpl.testWatch location=AtExit
ts=2024-09-26 19:38:49.137; [cost=0.4306ms] result=@ArrayList[@Object[][@ArrayList[@Integer[1],@String[test],@Integer[3],],],@HashMap[@String[1]:@Integer[1],@String[3]:@Integer[3],@String[test]:@String[test],],null,
]

参考文档

[1].官网文档

[2].demo项目地址