Arthas使用与线上问题排查实战

     arthas是阿里巴巴开源的线上诊断工具,可以在不重启项目的情况下修改某一些代码里面的参数,查看方法参数,并且可以监控当前整个项目的情况,例如可对:死锁,cpu飙高,oom等造成问题的代码堆栈进行导出,也可以实时查看某一个方法里面的详细耗时。他的具体实现为字节码插桩,类似动态aop帮你在方法执行前后执行一些操作.

下载

注意不能用root启动

# github下载arthas

wget https://alibaba.github.io/arthas/arthas-boot.jar
# 或者 Gitee 下载

wget https://arthas.gitee.io/arthas-boot.jar
用java -jar运行即可，可以识别机器上所有Java进程

常用排查问题命令

1.dashboard

可以看到项目整体情况

如下:

1.当前活跃线程,已经他的CPU使用情况

2.当前JVM情况,以及内存使用情况

3.当前运行环境

2.thread

可以查看最占用cpu的线程信息,以及查看死锁,我们线上可以用这个去查看一下为什么内存占用爆满,一般cpu最高的线程是造成我们OOM的元凶.

thread -n 5：打印前5个最忙的线程并打印堆栈
thread -all ：显示所有匹配的线程
thread -n 3 -i 1000 ：列出1000ms内最忙的3个线程栈
thread –state WAITING，查看指定状态的线程,（TIMED_WAITI、WAITING、RUNNABLE等等）
thread -b：找出阻塞其他线程的线程,当出现死锁后，会提示你出现死锁的位置

thread+线程id 打印当前线程的堆栈信息,例如下图可以看出大量线程卡在获取数据库连接.

例如下面看到线程池大量线程都是waiting状态，我们用thread 238,去打印堆栈信息，可以清楚看到当前代码阻塞的地方。

DruidDataSource.takeLast

3.trace

可以跟踪整个方法的调用链路以及每个链路的耗时以及执行的次数,不管是通过controller的接口还是通过mq来的消息.如果排查线上rt问题又没有做链路追踪,这个命令特别管用

trace 全类名+方法名  可以后面加管道符"|"表示多个方法.例如:trace -n1000 -E com.xxx.cabinet.service.v1.impl.DeviceHeartbeatServiceV1Impl dataHandler

线上案例:

机柜中心重构之后,我们发现机柜中心rocektmq处理消息特别慢,qps超过80的时候从mq接收消息,到下一个带事务的方法用了8秒,而接收消息到这个方法中间无任何代码,类似controller进入service一样,用了8秒.

伪代码

public void mqListener(String message){
     handler.handleMessage(message);
}


@Service
Class handler{
   
   @Transation
   void handleMessage(String message){
         //即上面mqListener到handleMessage的log.info使用了7秒，中间无任何代码
         log.info(handleMessage...) 
}
}

我们根据trace命令看到消耗时间的都是在springproxy的intercept方法,居然使用了7000ms,后面继续根据trace命令和根据thread命令看到实际上线程都阻塞在数据库的takeLast事件上(如上面thread命令的图).

我们就可以猜测,是数据库连接池满了导致的阻塞;

1.于是我们看了一下数据库连接池,并没问题.再改了应用配置数据库连接池大小,然后立即上线,发现qps仍然上不去,大量线程阻塞在takeLast事件上,线程池直接拉满,数据库连接池也继续拉满.

2.去掉@Transaction注解,继续上线,qps直接600+,这个时候猜测是长事务原因,但是以前压测并不会这样子.

3.观察了很久,在日志里面发现一个特点,就是有多台设备大量的重复消息(消息体并不一样,但是设备编号一样,需要不断更新同一台设备,抢数据库行锁),应该是设备sdk的bug,加上@Transaction注解范围太大了,机芯,电池每个孔位都得循环去对比然后修改数据库,导致都在争抢X锁,然后都获取不到连接,直接把应用的数据库连接池拉满.

4.优化点:这种复杂逻辑最好使用编程式事务,手动控制一下事务的粒度,减少锁的竞争.并且更新数据库可以走异步的方式，因为心跳对于我们来说重要程度没那么大。

使用命令打印出trace -n1000 -E com.xxx.xxx.service.v1.impl.DeviceHeartbeatServiceV1Impl dataHandler|shipDataHandler|checkSlotData|updateDeviceSlotAndBattery --skipJDKMethod false

可以看到每个方法的耗时和执行的次数

4.watch

可以看到方法的入参,出参

5.heapdump

类似 jmap 命令的 heap dump 功能

6.stop

关闭 Arthas 服务端，所有 Arthas 客户端全部退出