本文介绍几个非常有用的 Arthas 命令，熟练使用这几个命令，可以让我们在排查线上问题的时候更加轻松。
关于 Arthas 的设计思想，美团技术团队的文章Java 动态追踪技术探究一文中做了详细的说明，有兴趣可以去阅读一下。
trace
trace 命令见名知意，可以用于跟踪方法内部的调用路径，渲染整个调用链路上所有的性能开销和跟踪调用链路。
例如，我们提供了一个 controller，用来保存一笔订单数据，如下：
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
| package com.goku.order.rest;
import com.goku.order.entity.Order;
import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
import java.util.*;
@RestController
@RequestMapping("/api/orders")
@Slf4j
public class OrderRestController {
private static Random random = new Random();
@PostMapping
public Map<String, Object> save(@RequestBody Order order) {
long id = random.nextLong();
order.setId(id);
Date now = new Date();
if (Objects.nonNull(order.getFlag()) && order.getFlag()) {
log.info("调用路径1");
} else {
log.warn("调用路径2");
}
order.setCreateTime(now);
order.setUpdateTime(now);
log.info("request body : {}", order);
Map<String, Object> map = new HashMap<>(16);
map.put("order", order);
return map;
}
}
|
现在项目在运行中，我们要查看 save 方法的链路，打开 arthas 并选择我们的工程，使用 trace com.goku.order.rest.OrderRestController save 命令并触发一次调用
1
2
3
4
5
6
7
8
9
| Affect(class-cnt:1 , method-cnt:1) cost in 69 ms.
`---ts=2020-01-18 22:40:56;thread_name=http-nio-8081-exec-1;id=14;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@4f824872
`---[3.6313ms] com.goku.order.rest.OrderRestController:save()
+---[0.0164ms] com.goku.order.entity.Order:setId() #26
+---[0.0047ms] com.goku.order.entity.Order:getFlag() #28
+---[0.1695ms] org.slf4j.Logger:warn() #31
+---[0.0103ms] com.goku.order.entity.Order:setCreateTime() #33
+---[0.0062ms] com.goku.order.entity.Order:setUpdateTime() #34
`---[2.6388ms] org.slf4j.Logger:info() #35
|
从输出上来看，我们可以很清楚看到代码的 26、28、31、33、34、35 行被执行了，同样的，如果 order 对象的 flag 属性如果为 true，则第 31 行的调用会变成第 29 行，如下：
1
2
3
4
5
6
7
8
| `---ts=2020-01-18 22:56:00;thread_name=http-nio-8081-exec-4;id=17;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@4f824872
`---[2.1072ms] com.goku.order.rest.OrderRestController:save()
+---[0.0051ms] com.goku.order.entity.Order:setId() #26
+---[min=0.0023ms,max=0.0023ms,total=0.0046ms,count=2] com.goku.order.entity.Order:getFlag() #28
+---[0.6911ms] org.slf4j.Logger:info() #29
+---[0.0186ms] com.goku.order.entity.Order:setCreateTime() #33
+---[0.0032ms] com.goku.order.entity.Order:setUpdateTime() #34
`---[0.312ms] org.slf4j.Logger:info() #35
|
从输出结果也可以清楚的看到代码在执行过程中，哪一行的代码调用耗时最长，这对我们排查线上对应的问题是非常有帮助的。
包含 jdk 的函数
如果需要将 JDK 的方法执行链路也输出，则使用 --skipJDKMethod false 参数，例如： trace com.goku.order.rest.OrderRestController save --skipJDKMethod false。
根据调用耗时过滤
如果需要只需要查看调用耗时比较长的，则添加对应的过滤条件，可以更快的帮助我们定位异常问题。比如只查询调用耗时超过 10ms 的方法：trace com.goku.order.rest.OrderRestController save '#cost > 10'