Arthas - Java 线上问题定位处理的终极利器 Hollis 2019-11-09 如下文章来源于未读代码 ,做者达西java
转载:mp.weixin.qq.com/s?subscene=…mysql
在使用 Arthas 以前,当遇到 Java 线上问题时,如 CPU 飙升、负载突高、内存溢出等问题,你须要查命令,查网络,而后 jps、jstack、jmap、jhat、jstat、hprof 等一通操做。最终焦头烂额,还不必定能查出问题所在。而如今,大多数的常见问题你均可以使用 Arthas 轻松定位,迅速解决,及时止损,准时下班。git
Arthas 是 Alibaba 在 2018 年 9 月开源的 Java 诊断工具。支持 JDK6+, 采用命令行交互模式,提供 Tab 自动不全,能够方便的定位和诊断线上程序运行问题。截至本篇文章编写时,已经收获 Star 17000+。github
Arthas 官方文档十分详细,本文也参考了官方文档内容,同时在开源在的 Github 的项目里的 Issues 里不只有问题反馈,更有大量的使用案例,也能够进行学习参考。web
开源地址:github.com/alibaba/art…redis
官方文档:alibaba.github.io/arthasspring
得益于 Arthas 强大且丰富的功能,让 Arthas 能作的事情超乎想象。下面仅仅列举几项常见的使用状况,更多的使用场景能够在熟悉了 Arthas 以后自行探索。sql
是否有一个全局视角来查看系统的运行情况?express
为何 CPU 又升高了,究竟是哪里占用了 CPU ?apache
运行的多线程有死锁吗?有阻塞吗?
程序运行耗时很长,是哪里耗时比较长呢?如何监测呢?
这个类从哪一个 jar 包加载的?为何会报各类类相关的 Exception?
我改的代码为何没有执行到?难道是我没 commit?分支搞错了?
遇到问题没法在线上 debug,难道只能经过加日志再从新发布吗?
有什么办法能够监控到 JVM 的实时运行状态?
前文已经提到,Arthas 是一款命令行交互模式的 Java 诊断工具,因为是 Java 编写,因此能够直接下载相应 的 jar 包运行。
3.1 安装 能够在官方 Github 上进行下载,若是速度较慢,能够尝试国内的码云 Gitee 下载。
wget alibaba.github.io/arthas/arth…
wget arthas.gitee.io/arthas-boot…
java -jar arthas-boot.jar -h 3.2 运行 Arthas 只是一个 java 程序,因此能够直接用 java -jar 运行。运行时或者运行以后要选择要监测的 Java 进程。
java -jar arthas-boot.jar
[INFO] arthas-boot version: 3.1.4 [INFO] Found existing java process, please choose one and hit RETURN.
java -jar arthas-boot.jar [PID] 查看 PID 的方式能够经过 ps 命令,也能够经过 JDK 提供的 jps命令。
$ jps -mlvV
$ jps -mlvV | grep [xxx] jps 筛选想要的进程方式。
在出现 Arthas Logo 以后就可使用命令进行问题诊断了。下面会详细介绍。
更多的启动方式能够参考 help 帮助命令。
EXAMPLES: java -jar arthas-boot.jar java -jar arthas-boot.jar --target-ip 0.0.0.0 java -jar arthas-boot.jar --telnet-port 9999 --http-port -1 java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws' 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' java -jar arthas-boot.jar -f batch.as java -jar arthas-boot.jar --use-version 3.1.4 java -jar arthas-boot.jar --versions java -jar arthas-boot.jar --session-timeout 3600 java -jar arthas-boot.jar --attach-only java -jar arthas-boot.jar --repo-mirror aliyun --use-http 3.3 web console Arthas 目前支持 Web Console,在成功启动链接进程以后就已经自动启动,能够直接访问 http://127.0.0.1:8563/ 访问,页面上的操做模式和控制台彻底同样。
3.4 经常使用命令
下面列举一些 Arthas 的经常使用命令,看到这里你可能还不知道怎么使用,别急,后面会一一介绍。
命令 介绍 dashboard 当前系统的实时数据面板 thread 查看当前 JVM 的线程堆栈信息 watch 方法执行数据观测 trace 方法内部调用路径,并输出方法路径上的每一个节点上耗时 stack 输出当前方法被调用的调用路径 tt 方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不一样的时间下调用进行观测 monitor 方法执行监控 jvm 查看当前 JVM 信息 vmoption 查看,更新 JVM 诊断相关的参数 sc 查看 JVM 已加载的类信息 sm 查看已加载类的方法信息 jad 反编译指定已加载类的源码 classloader 查看 classloader 的继承树,urls,类加载信息 heapdump 相似 jmap 命令的 heap dump 功能 3.5 退出 使用 shutdown 退出时 Arthas 同时自动重置全部加强过的类 。
上面已经了解了什么是 Arthas,以及 Arthas 的启动方式,下面会依据一些状况,详细说一说 Arthas 的使用方式。在使用命令的过程当中若是有问题,每一个命令均可以是 -h 查看帮助信息。
首先编写一个有各类状况的测试类运行起来,再使用 Arthas 进行问题定位,
import java.util.HashSet; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import lombok.extern.slf4j.Slf4j;
/**
Arthas Demo
公众号:未读代码
@Author niujinpeng */ @Slf4j public class Arthas {
private static HashSet hashSet = new HashSet(); /** 线程池,大小1*/ private static ExecutorService executorService = Executors.newFixedThreadPool(1);
public static void main(String[] args) { // 模拟 CPU 太高,这里注释掉了,测试时能够打开 // cpu(); // 模拟线程阻塞 thread(); // 模拟线程死锁 deadThread(); // 不断的向 hashSet 集合增长数据 addHashSetThread(); }
/**
public static void cpu() { cpuHigh(); cpuNormal(); }
/**
/**
/**
/**
死锁 / private static void deadThread() { /* 建立资源 */ Object resourceA = new Object(); Object resourceB = new Object(); // 建立线程 Thread threadA = new Thread(() -> { synchronized (resourceA) { log.info(Thread.currentThread() + " get ResourceA"); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } log.info(Thread.currentThread() + "waiting get resourceB"); synchronized (resourceB) { log.info(Thread.currentThread() + " get resourceB"); } } });
Thread threadB = new Thread(() -> { synchronized (resourceB) { log.info(Thread.currentThread() + " get ResourceB"); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } log.info(Thread.currentThread() + "waiting get resourceA"); synchronized (resourceA) { log.info(Thread.currentThread() + " get resourceA"); } } }); threadA.start(); threadB.start(); } } 4.1 全局监控 使用 dashboard 命令能够概览程序的 线程、内存、GC、运行环境信息。
dashboard 4.2 CPU 为何起飞了 上面的代码例子有一个 CPU 空转的死循环,很是的消耗 CPU性能,那么怎么找出来呢?
使用 thread查看全部线程信息,同时会列出每一个线程的 CPU 使用率,能够看到图里 ID 为12 的线程 CPU 使用100%。
使用命令 thread 12 查看 CPU 消耗较高的 12 号线程信息,能够看到 CPU 使用较高的方法和行数(这里的行数可能和上面代码里的行数有区别,由于上面的代码在我写文章时候从新排过版了)。
上面是先经过观察整体的线程信息,而后查看具体的线程运行状况。若是只是为了寻找 CPU 使用较高的线程,能够直接使用命令 thread -n [显示的线程个数] ,就能够排列出 CPU 使用率 Top N 的线程。
定位到的 CPU 使用最高的方法。
4.3 线程池线程状态 定位线程问题以前,先回顾一下线程的几种常见状态:
RUNNABLE 运行中
TIMED_WAITIN 调用了如下方法的线程会进入TIMED_WAITING:
Thread#sleep()
Object#wait() 并加了超时参数
Thread#join() 并加了超时参数
LockSupport#parkNanos()
LockSupport#parkUntil()
WAITING 当线程调用如下方法时会进入WAITING状态:
Object#wait() 并且不加超时参数
Thread#join() 并且不加超时参数
LockSupport#park()
BLOCKED 阻塞,等待锁
上面的模拟代码里,定义了线程池大小为1 的线程池,而后在 cpuHigh 方法里提交了一个线程,在 thread方法再次提交了一个线程,后面的这个线程由于线程池已满,会阻塞下来。
使用 thread | grep pool 命令查看线程池里线程信息。
能够看到线程池有 WAITING 的线程。
4.4 线程死锁 上面的模拟代码里 deadThread方法实现了一个死锁,使用 thread -b 命令查看直接定位到死锁信息。
/**
死锁 / private static void deadThread() { /* 建立资源 */ Object resourceA = new Object(); Object resourceB = new Object(); // 建立线程 Thread threadA = new Thread(() -> { synchronized (resourceA) { log.info(Thread.currentThread() + " get ResourceA"); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } log.info(Thread.currentThread() + "waiting get resourceB"); synchronized (resourceB) { log.info(Thread.currentThread() + " get resourceB"); } } });
Thread threadB = new Thread(() -> { synchronized (resourceB) { log.info(Thread.currentThread() + " get ResourceB"); try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); } log.info(Thread.currentThread() + "waiting get resourceA"); synchronized (resourceA) { log.info(Thread.currentThread() + " get resourceA"); } } }); threadA.start(); threadB.start(); } 检查到的死锁信息。
4.5 反编译 上面的代码放到了包 com下,假设这是一个线程环境,当怀疑当前运行的代码不是本身想要的代码时,能够直接反编译出代码,也能够选择性的查看类的字段或方法信息。
若是怀疑不是本身的代码,可使用 jad 命令直接反编译 class。
jad jad 命令还提供了一些其余参数:
jad --source-only com.Arthas
jad --source-only com.Arthas mysql 4.6 查看字段信息 使用 **sc -d -f ** 命令查看类的字段信息。
[arthas@20252]AppClassLoader@18b4aac2 +-sun.misc.Launcher$ExtClassLoader@2ef1e4fa classLoaderHash 18b4aac2 fields modifierfinal,private,static type org.slf4j.Logger name log value Logger[com.Arthas]
modifierprivate,static
type java.util.HashSet
name hashSet
value [count1, count2]
modifierprivate,static
type java.util.concurrent.ExecutorService
name executorService
value java.util.concurrent.ThreadPoolExecutor@71c03156[Ru
nning, pool size = 1, active threads = 1, queued ta
sks = 0, completed tasks = 0]
复制代码
Affect(row-cnt:1) cost in 9 ms. 4.7 查看方法信息 使用 sm 命令查看类的方法信息。
[arthas@22180]cpuHigh
thread
addHashSetThread
deadThread
deadThread
cpuNormal$2()V Affect(row-cnt:16) cost in 6 ms. 4.8 对变量的值非常好奇 使用 ognl 命令,ognl 表达式能够轻松操做想要的信息。
代码仍是上面的示例代码,咱们查看变量 hashSet 中的数据:
查看静态变量 hashSet 信息。
[arthas@19856]$ ognl '@com.Arthas@hashSet' @HashSet[ @String[count1], @String[count2], @String[count29], @String[count28], @String[count0], @String[count27], @String[count5], @String[count26], @String[count6], @String[count25], @String[count3], @String[count24], 查看静态变量 hashSet 大小。
[arthas@19856]$ ognl '@com.Arthas@hashSet.size()' @Integer[57] 甚至能够进行操做。
[arthas@19856]
[arthas@19856] ognl 能够作不少事情,能够参考 ognl 表达式特殊用法( github.com/alibaba/art… )。
4.9 程序有没有问题 4.9.1 运行较慢、耗时较长 使用 trace 命令能够跟踪统计方法耗时
此次换一个模拟代码。一个最基础的 Springboot 项目(固然,不想 Springboot 的话,你也能够直接在 UserController 里 main 方法启动)控制层 getUser 方法调用了 userService.get(uid);,这个方法中分别进行check、service、redis、mysql操做。
@RestController @Slf4j public class UserController {
@Autowired
private UserServiceImpl userService;
@GetMapping(value = "/user")
public HashMap<String, Object> getUser(Integer uid) throws Exception {
// 模拟用户查询
userService.get(uid);
HashMap<String, Object> hashMap = new HashMap<>();
hashMap.put("uid", uid);
hashMap.put("name", "name" + uid);
return hashMap;
}
复制代码
} 模拟代码 Service:
@Service @Slf4j public class UserServiceImpl {
public void get(Integer uid) throws Exception {
check(uid);
service(uid);
redis(uid);
mysql(uid);
}
public void service(Integer uid) throws Exception {
int count = 0;
for (int i = 0; i < 10; i++) {
count += i;
}
log.info("service end {}", count);
}
public void redis(Integer uid) throws Exception {
int count = 0;
for (int i = 0; i < 10000; i++) {
count += i;
}
log.info("redis end {}", count);
}
public void mysql(Integer uid) throws Exception {
long count = 0;
for (int i = 0; i < 10000000; i++) {
count += i;
}
log.info("mysql end {}", count);
}
public boolean check(Integer uid) throws Exception {
if (uid == null || uid < 0) {
log.error("uid不正确,uid:{}", uid);
throw new Exception("uid不正确");
}
return true;
}
复制代码
} 运行 Springboot 以后,使用 **trace== ** 命令开始检测耗时状况。
[arthas@6592]$ trace com.UserController getUser 访问接口 /getUser ,能够看到耗时信息,看到 com.UserServiceImpl:get()方法耗时较高。
继续跟踪耗时高的方法,而后再次访问。
[arthas@6592]$ trace com.UserServiceImpl get
很清楚的看到是 com.UserServiceImpl的 mysql方法耗时是最高的。
Affect(class-cnt:1 , method-cnt:1) cost in 31 ms. ---ts=2019-10-16 14:40:10;thread_name=http-nio-8080-exec-8;id=1f;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@23a918c7
---[6.792201ms] com.UserServiceImpl:get() +---[0.008ms] com.UserServiceImpl:check() #17 +---[0.076ms] com.UserServiceImpl:service() #18 +---[0.1089ms] com.UserServiceImpl:redis() #19 `---[6.528899ms] com.UserServiceImpl:mysql() #20 4.9.2 统计方法耗时 使用 monitor 命令监控统计方法的执行状况。
每5秒统计一次 com.UserServiceImpl 类的 get 方法执行状况。
monitor -c 5 com.UserServiceImpl get
4.10 想观察方法信息 下面的示例用到了文章的前两个模拟代码。
4.10.1 观察方法的入参出参信息 使用 watch 命令轻松查看输入输出参数以及异常等信息。
USAGE: watch [-b] [-e] [-x ] [-f] [-h] [-n ] [-E] [-M ] [-s] class-pattern method-pattern express [condition-express]
SUMMARY: Display the input/output parameter, return object, and thrown exception of specified method invocation The express may be one of the following expression (evaluated dynamically): target : the object clazz : the object's class method : the constructor or method params : the parameters array of method params[0..n] : the element of parameters array returnObj : the returned object of method throwExp : the throw exception of method isReturn : the method ended by return isThrow : the method ended by throwing exception #cost : the execution time in ms of method invocation Examples: watch -b org.apache.commons.lang.StringUtils isBlank params watch -f org.apache.commons.lang.StringUtils isBlank returnObj watch org.apache.commons.lang.StringUtils isBlank '{params, target, returnObj}' -x 2 watch -bf *StringUtils isBlank params watch *StringUtils isBlank params[0] watch *StringUtils isBlank params[0] params[0].length==1 watch *StringUtils isBlank params '#cost>100' watch -E -b org.apache.commons.lang.StringUtils isBlank params[0]
WIKI: alibaba.github.io/arthas/watc… 经常使用操做:
$ watch com.Arthas addHashSet '{params[0],returnObj}'
$ watch com.Arthas addHashSet '{params[0],returnObj.size}'
$ watch com.Arthas addHashSet '{params[0],returnObj.contains("count10")}'
$ watch com.Arthas addHashSet '{params[0],returnObj.toString()}' 查看入参出参。
查看返回的异常信息。
4.10.2 观察方法的调用路径 使用 stack命令查看方法的调用信息。
stack com.UserServiceImpl mysql 能够看到调用路径如图。
4.10.3 方法调用时空隧道 使用 tt 命令记录方法执行的详细状况。
tt 命令方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不一样的时间下调用进行观测 。
经常使用操做:
开始记录方法调用信息:tt -t com.UserServiceImpl check
能够看到记录中 INDEX=1001 的记录的 IS-EXP = true ,说明此次调用出现异常。
查看记录的方法调用信息:tt -l
查看调用记录的详细信息(-i 指定 INDEX):tt -i 1001
能够看到 INDEX=1001 的记录的异常信息。
从新发起调用,使用指定记录,使用 -p 从新调用。
tt -i 1001 -p 结果如图。
文中代码已经上传到 Github。