背景说明
项目上某个接口响应时间过长，需要查看方法耗时情况进行优化
安装配置
- 访问下载页进行下载：下载 | 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 Arthas
NOTE: 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 -1
java -jar arthas-boot.jar --username admin --password <password>
java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
--app-name demoapp
java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws'
--agent-id bvDOe8XbTM2pQWjF4cfw
java -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.1
java -jar arthas-boot.jar --versions
java -jar arthas-boot.jar --select math-game
java -jar arthas-boot.jar --session-timeout 3600
java -jar arthas-boot.jar --attach-only
java -jar arthas-boot.jar --disabled-commands stop,dump
java -jar arthas-boot.jar --repo-mirror aliyun --use-http
WIKI:
https://arthas.aliyun.com/doc
Options and Arguments:
--use-http Enforce use http to download, default use
https
--repo-mirror <value> Use special remote repository mirror, value is
center/aliyun or http repo url.
--stat-url <value> The report stat url
--select <value> select target process by classname or
JARfilename
--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, default
3658
-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 commands
separated 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;
@Autowired
public 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);
@Override
public 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() #34
Command 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() #21
Command 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项目地址
