线上问题排查利器Arthas

作为一名开发，最头疼最担心的莫过于生产环境出问题了。生产无小事，一出问题，轻则影响用户体验，造成客诉，重则造成公司资损，后果严重。

当然，上线前如何充分测试，线上出问题之后如何快速止血这些不在本文介绍范围之内，本文主要介绍如何快速定位问题。线上问题复杂多样，CPU飙升、RT突增、内存不足、性能下降等等，如何才能在最短时间内定位到问题呢？下面就来安利这款线上问题定位神器：Arthas。

Arthas是一款阿里开源的Java诊断工具，对业务代码无侵入，功能强悍，安装简单，上手快，深受Java开发者喜爱。文档见：https://arthas.aliyun.com/doc。

不过纸上得来终觉浅，本文就通过几个场景，结合自己写的简单demo，让大家一起领略下Arthas的魅力。

项目A上线完成，功能一切正常，观察半小时后准备打卡下班，刚下楼，报警短信来了，一看是CPU报警，CPU使用率300%，心凉了半截，火速跑回工位……

其实如果是代码问题，利用Linux和JVM的原生命令，也可以定位，具体方式见：https://blog.csdn.net/qq_22978533/article/details/80459407。博主用了一篇文章的篇幅来介绍如何定位，那如果是交给Arthas来做呢？一行命令！下面通过一个demo来看一下。

死循环往一个map里面put数据，造成CPU飙升：

static void testCPU(){
  while (true){
    for(int i=0;i<10000;i++){
      HOLDER.put(i,i);
    }
    HOLDER.clear();
  }
}

Arthas定位：

[arthas@27969]$ thread -n 3
"main" Id=1 cpuUsage=99% RUNNABLE
  at java.util.concurrent.ConcurrentHashMap.clear(ConcurrentHashMap.java:1206)
  at com.ljy.test.arthas.demo.CPUDemo.testCPU(CPUDemo.java:27)
  at com.ljy.test.arthas.demo.CPUDemo.main(CPUDemo.java:55)

可以直接定位到出问题的类及代码行，是不是很简单？接下来再看一个因为死锁造成的CPU飚高问题：

static void testDeadLock(){
  new Thread(()->{
    LOCK1.lock();
    try {
      Thread.sleep(1000);
    } catch (InterruptedException e) {
      e.printStackTrace();
    }
    LOCK2.lock();
  }).start();

  new Thread(()->{
    LOCK2.lock();
    try {
      Thread.sleep(1000);
    } catch (InterruptedException e) {
      e.printStackTrace();
    }
    LOCK1.lock();
  }).start();
}

同样，一行命令找到死锁位置：

 [arthas@28004]$ thread -b
"Thread-0" Id=11 WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@4bcf34d owned by "Thread-1" Id=12
  at sun.misc.Unsafe.park(Native Method)
  -  waiting on java.util.concurrent.locks.ReentrantLock$NonfairSync@4bcf34d
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
  at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
  at com.ljy.test.arthas.demo.CPUDemo.lambda$testDeadLock$0(CPUDemo.java:39)
  at com.ljy.test.arthas.demo.CPUDemo$$Lambda$1/769287236.run(Unknown Source)
  at java.lang.Thread.run(Thread.java:748)

  Number of locked synchronizers = 1
  - java.util.concurrent.locks.ReentrantLock$NonfairSync@6b008751 <---- but blocks 1 other threads!

场景二

小A花了一周的时间，终于把一个大需求开发完了，并且在本机上测试通过，长长的出了一口气，吹起口哨，准备部署到测试环境提测，多么美好的一天。提交代码，打包部署，几分钟后，部署完成，测一下刚才没问题的功能点吧，然后，嗯？找不到类？找不到方法？明明刚测过的啊，我是谁？我在那？……

通常这种情况，我们都会想到可能是代码分支的问题，有可能部署了错误的分支，也有可能你刚提交完代码，同事也在同一个分支上提交了代码，影响了之前的功能，除此之外，下面一些情况应该也是很多开发同学遇到过的：

• 项目应用了很多第三方jar包，这些jar包里面有一些类命或者方法名是重复的，引用的jar包跟实际需要引用的jar包不一致。例如StringUtils

• jar包版本冲突问题

• 因为手速太快，类名或者方法名少/多打了一个字母，肉眼排查过程痛不欲生

这类怎么确定呢？来看Arthas的sc-d(Search Class)、sm(Search Method)、jad(Java Decompile)三连击快速定位问题。

想知道一个类有没有真正的加载到jvm中，可以用sc命令，效果如下：

[arthas@30314]$ sc com.ljy.test.util.DemoUtils
com.ljy.test.util.DemoUtils
Affect(row-cnt:1) cost in 6 ms.

[arthas@30314]$ sc com.ljy.test.util.DemoUtil
Affect(row-cnt:0) cost in 5 ms.

悄悄的告诉你，arthas是支持正则表达式的，对于像我这种不爱记包名的懒人，无疑是个好消息，对于上面的例子，用下面的方式也是一样的效果：

[arthas@30314]$ sc *DemoUtils
com.ljy.test.util.DemoUtils
Affect(row-cnt:1) cost in 9 ms.

同样这个参数，加上一个-d选项，就是排查定位jar包问题的利器，可以直接定位到是从哪个jar包加载进来的：

[arthas@30651]$ sc -d org.apache.commons.lang3.StringUtils
class-info  org.apache.commons.lang3.StringUtils
code-source  /xxx/repository/org/apache/commons/commons-lang3/3.10/commons-lang3-3.10.jar

sm跟sc是类似的，只需要在sc的基础上，在后面加上需要查找的方法名即可，这里不再赘述。

接下来就是定位线上环境中，运行效果与预期不符的问题了，也就是证明正在跑的代码，是“我认为应该”跑的代码，用jad命令，直接展示效果：

[arthas@30651]$ jad *DemoUtils

ClassLoader:
+-sun.misc.Launcher$AppClassLoader@18b4aac2
  +-sun.misc.Launcher$ExtClassLoader@6344b56e

Location:
/Users/lijianying/sourcecodes/daily_test/target/classes/

/*
 * Decompiled with CFR.
 */
package com.ljy.test.util;

import java.io.IOException;
import org.apache.commons.lang3.StringUtils;

public class DemoUtils {
  void methodA() {
  }

  void methodB() {
  }

  void methodc() {
  }
}

类加载器、类所在位置、类的内容一目了然，线上跑的就是这些代码，如果与预期不符，就检查一下自己改动的代码是否跟反编译出来的代码一致，快速定位到分支冲突。

场景三

一个项目B上线完成，小组组织团建，大家正在吃着火锅唱着歌，突然客服妹子来电话了，说一个客户投诉好几次了，下单失败，重试多次都不行，请尽快解决。瞬间感觉酒杯里的酒都不香了……好在客诉只有一个用户，没有大面积故障，应该是这个用户触发了某个BUG。放下酒杯，拿出电脑，连上WIFI开始排查问题。

这类问题还是比较棘手的，常规排查方法有三种，如果问题可以在测试环境或者本地复现，可以debug还好一些，但是通常测试数据跟线上还是有区别的，该方法不一定能奏效。另一种办法就是线上debug，不过该方法存在如下问题：一来线上环境一般是数台机器，不能确定有问题的请求打到哪台机器上，效率较低，二来会阻塞其他正常请求，因此强烈建议不要在生产环境使用线上Debug方式排查问题。再有一种方法，就是修改代码，在可能出问题的地方加日志，重新发布一台线上机器定位问题，定位到之后再改代码重新上线，无疑也是效率低下的。

下面介绍一下Arthas提供的强大的观察类在运行时情况的命令：watch，该命令可以实时观察方法的出入参以及异常情况，而且可以支持OGNL表达式，方便根据出问题的参数精准的定位问题。用以下demo模拟上述场景，即只在特殊情况下触发问题：

public class TroubleShootDemo {
  private static final String[] ARR = new String[]{"a","b","c","d","e"};

  /**
   * 模拟特定参数的时候才会触发的逻辑
   * @param param
   * @return
   */
  private static String invoke(String param){
    if("a".equals(param)){
      return "success";
    }
    return "failed";
  }

  public static void main(String[] args) throws InterruptedException {
    while (true){
      //模拟小概率出现
      int index = RandomUtils.nextInt(0,1000);
      if(index<5){
        invoke(ARR[index]);
      }
      Thread.sleep(1);
    }
  }
}

我们先来看一下正常观察出入参的用法：

[arthas@31318]$ watch *TroubleShootDemo invoke "{params,returnObj}" -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 32 ms, listenerId: 2
ts=2020-08-18 17:23:14; [cost=0.224202ms] result=@ArrayList[
  @Object[][
    @String[b],
  ],
  @String[failed],
]
ts=2020-08-18 17:23:15; [cost=0.142852ms] result=@ArrayList[
  @Object[][
    @String[c],
  ],
  @String[failed],
]
ts=2020-08-18 17:23:15; [cost=0.127154ms] result=@ArrayList[
  @Object[][
    @String[d],
  ],
  @String[failed],
]
ts=2020-08-18 17:23:15; [cost=0.132717ms] result=@ArrayList[
  @Object[][
    @String[a],
  ],
  @String[success],
]

可以很清楚的看到TroubleShootDemo类的invoke方法，每次调用的出入参情况，其中 -x 2 表示展示出入参的层次为2层。当然生产环境下直接这么用是不行的，请求量大，刷新太快，需要用OGNL表达式对制定参数做过滤，方便更精准的定位问题：

[arthas@1318]$ watch *TroubleShootDemo invoke "{params,returnObj}" 'params[0]=="a"' -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 32 ms, listenerId: 3
ts=2020-08-18 18:41:04; [cost=0.078229ms] result=@ArrayList[
  @Object[][
    @String[a],
  ],
  @String[success],
]
ts=2020-08-18 18:41:06; [cost=0.115137ms] result=@ArrayList[
  @Object[][
    @String[a],
  ],
  @String[success],
]

这样就能清楚的看到指定参数的请求，出入参及异常时候的真实状况，可以快速判断是不是该方法造成的线上问题。

场景四

一个项目C上线了半年多了，支撑了大量的业务，运行一直很稳定，没出过任何线上事故，可是最近几周，随着这个项目的日益火爆，里面几个接口的请求速度越来越慢，高峰期有时候的响应速度都快达到2秒，这样下去再过几天就要出大事了，得赶紧排查一下为毛慢了这么多。
可是从哪里下手呢？是新上线的改动造成的么？还是请求量大了导致fullGC增多？或者是数据量太大了数据库扛不住了？又或者是代码里面调用的第三方服务出了问题？顿时陷入了沉思……

这应该算是性能优化的范畴了，Arthas提供了trace这个强大的命令，能够迅速的定位到影响性能的元凶。以下demo模拟了业务代码中多个方法调用，其中一个方法调用耗时较长：

public class ArthasDemo {

  void methodA() throws InterruptedException {
    Thread.sleep(20);
  }

  void methodB() throws InterruptedException {
    Thread.sleep(50);
  }
  
  void methodC() throws InterruptedException {
    Thread.sleep(1000);
  }

  void invoke() throws InterruptedException {
    methodB();
    methodC();
    methodA();
  }
}

trace之后，可以直接定位到每个方法的耗时，其中耗时较长的方法会红色标注，这样一眼就定位到到底是哪个方法在“拖后腿”，之后就可以进行有针对性的优化，以提升性能。

[arthas@1638]$ trace *ArthasDemo invoke
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 50 ms, listenerId: 2
`---ts=2020-08-18 19:44:36;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2
  `---[1079.223985ms] com.ljy.test.util.ArthasDemo:invoke()
    +---[52.155584ms] com.ljy.test.util.ArthasDemo:methodB() #25
    +---[1002.240458ms] com.ljy.test.util.ArthasDemo:methodC() #26
    `---[21.386992ms] com.ljy.test.util.ArthasDemo:methodA() #27

该命令也是支持OGNL表达式的，比如我们想只查看耗时超过10ms的方法：

[arthas@1692]$ trace com.ljy.test.util.ArthasDemo invoke #cost>10
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 90 ms, listenerId: 2
`---ts=2020-08-18 19:53:19;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2
  `---[1082.629181ms] com.ljy.test.util.ArthasDemo:invoke()
    +---[54.860407ms] com.ljy.test.util.ArthasDemo:methodB() #23
    +---[1003.365012ms] com.ljy.test.util.ArthasDemo:methodC() #24
    `---[23.094037ms] com.ljy.test.util.ArthasDemo:methodA() #25

场景五

公司筹备了半年的一场大促还有10分钟就要开始了，就在这时发现了一行代码BUG，有几率影响到最关键的秒杀活动，几十上百台机器，想修改代码再发布已经来不及了，整个项目组都急的像热锅上的蚂蚁……

这时候就需要祭出Arthas的黑科技redefine，它可以直接替换掉运行时JVM中某个class文件，可谓是给飞驰的赛车换轮胎，下面通过demo来演示一下效果：

public class RedefineDemo {
  void method(){
    System.out.println("before");
  }
}

public class Test {
  public static void main(String[] args) throws IOException {
    RedefineDemo demo = new RedefineDemo();
    demo.method();
    System.in.read();
    demo.method();
  }
}

我们先运行Test中的main方法，打印出的是“before”，System.in.read()将线程挂起，但是jvm不退出。然后我们修改RedefineDemo中的method，改为打印“after”，之后编译该类，得到RedefineDemo.class文件，之后使用redefine命令，将编译得到的class文件，替换掉之前的文件。

[arthas@1849]$ redefine /Users/lijianying/sourcecodes/daily_test/src/main/java/com/ljy/test/arthas/demo/RedefineDemo.class
redefine success, size: 1, classes:
com.ljy.test.arthas.demo.RedefineDemo

接下来就是见证奇迹的时刻了，我们在控制台敲下回车，同样的方法调用，jvm没有停止的前提下，控制台打印出了"after"(这就意味着可以在线上服务不重启的情况下，替换某个类的执行逻辑)：

然后开头提到的问题就可以解决了，编写脚本，批量替换掉线上服务器有问题的类文件即可。当然，本demo只是为了掩饰Arthas的强悍，这种方法是极其危险的，替换掉的类不能被恢复，并且存在替换失败的可能。因此，不到万不得已，尽量不要使用该命令。

本文主要介绍了在遇到不同线上问题的时候，如何使用Arthas快速的定位问题，可以简单了解Arthas在CPU问题、代码版本冲突问题、方法实时运行问题、性能优化问题等几个场景的作用，当然文中的demo都是为了展示用法临时写的，真正线上问题可能复杂的多，不过Arthas的合理运用肯定会让诸位在排查问题的时候事半功倍。希望本文能帮助到各位开发小伙伴，后续如果遇到真实的线上案例，也会继续分享给大家。