阿里Java诊断工具 arthas - 排查线上环境内存使用过大线程cpu使用率高问题

Posted 2023-01-12 小毕超

一、arthas

上篇文章对arthas的安装以及指令做了展示，可以感觉出arthas提供的指令还是挺多的，上篇文章没有对指令进行过多的演示，目的是大家在学习arthas后，就可以在上篇文章或者官方文档中统一查找定位使用哪个指令了，本篇文章借助arthas排查应用内存使用过大、线程cpu使用率高问题，可以加深大家对arthas指令的理解。

下面是上篇文章的地址：

https://blog.csdn.net/qq_43692950/article/details/122686329

二、排查应用内存使用过大、或者内存溢出问题

构建问题环境

在开始前我们先准备测试的应用，这里可以新建一个SpringBoot项目，在项目中我们故意写一个占用内存的BUG：

@RestController
public class JvmThreadController 
    List<byte[]> memoryList = new ArrayList<>();
    
    @GetMapping("/memoryTest")
    public String memoryTest(int c) 
        byte[] b = new byte[c * 1024 * 1024];
        memoryList.add(b);
        return "success";
    

上面我们创建了一个controller，声明了一个byte[]类型的 memoryList 列表，并在memoryTest接口中对memoryList每次以 c兆的大小进行塞值，由于memoryList是全局变量，并不会被GC回收所以，以此我们就可以达到内存占用量大的目的了。

在启动时，我们最好也指定下JVM的参数，将最大堆内容设为50M，这样就可以很快出现OOM的问题了,并且我们也可以打印出内存溢出时的hprof文件：

java -Xmx50m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/java/ -jar demo.jar 

下面多调用几次memoryTest接口：

已经出现问题，下面我们开始排除问题

排查问题

使用arthas连接到该应用，先使用dashboard查看下当前内存使用情况：

可以看到堆的使用率，以及老年代的使用率都接近满的状态了，如果我们应用没有大的对象，那就是肯定某个对象站用了大量的空间。

使用arthas生成内存分区的火焰图：

 profiler start --event alloc

等待一会，获取已采集的sample的数量

profiler getSamples

停止采集，并生成html文件，后面时文件存放的地址

profiler stop --format html --file /java/output.html

将output.html文件从生产环境导出到本地，用浏览器打开：

可以看到是一个调用链，下面就要看每个链的末尾，具体时哪个地方占用的内存：

从上面应该可以得到问题所在，是在com/bxc/arthasdemo/controller/JvmThreadController.memoryTest方法，并且和byte[]有关，还和java.util.ArrayDeque有关，查看这个地方的代码，应该不难看出问题了。

下面还可以使用heapdump将此时的hprof快照文件导出，使用MAT工具再进行分析，是不是还是将问题定位到上面的地方：

生成hprof快照：

heapdump /java/heapdump.hprof

将heapdump.hprof文件导出使用MAT打开，并查看Leak Suspects：

可以看到给出了两个问题：

查看第一个问题的详情：

看到这个地方也是比较明确了问题所在。

三、排查线程cpu使用率高问题

上面排查了内存使用大、内存溢出的问题，在实际生产环境应用中，可能还会出现线程的cpu使用率占用也别高，导致资源耗费殆尽，程序运行缓慢，这种情况arthas也可以方便的帮我们定位问题所在。

还有线程死锁也是一个非常头疼的问题，不仅锁住了资源，还会导致线程无法释放，持续占用资源，使用arthas我们可以快速定位问题

CPU使用率高问题

在开始前还是构建一个CPU使用率高的环境，创建一个controller：

@RestController
public class JvmThreadController 

    ThreadPoolExecutor executor = new ThreadPoolExecutor(
            10,
            15,
            2,
            TimeUnit.SECONDS,
            new LinkedBlockingDeque<>(50),
            new ThreadPoolExecutor.CallerRunsPolicy()
    );

    @GetMapping("/cpuUsageRate")
    public String cpuUsageRate() 
        executor.submit(() -> 
            int i = 0;
            while (true) 
                i = i++ * 10 + 5;
                System.out.println(i);
            
        );
        return "success";
    

上面声明了一个线程池，每次使用线程就从这个里面取，在cpuUsageRate接口中，写了一个死循环，每次都对i进行计算，程序运行起来，肯定cpu的使用率特别高。

启动应用，调用cpuUsageRate接口。

可以看到已经有一个线程的使用率达到了100%

下面在使用thread 查看下总体线程的使用：

依然是有一个线程使用率达到100%，查看这个线程的具体信息：

thread 54

这里提示是JvmThreadController的91行，我们看下程序：

正是我们这个线程写的死循环占用了大量cpu的资源。

下面我们在使用thread -n 2 查看前两个占用高的线程：

thread -n 2

还是将位置定位到了JvmThreadController的91行。

线程死锁问题

上面我们定位到cpu使用率大的线程及定位到了具体位置，这里我们继续定位线程死锁问题，在开始前我们先构建一个死锁的环境：

@RestController
public class JvmThreadController 

    ThreadPoolExecutor executor = new ThreadPoolExecutor(
            10,
            15,
            2,
            TimeUnit.SECONDS,
            new LinkedBlockingDeque<>(50),
            new ThreadPoolExecutor.CallerRunsPolicy()
    );
 
    @GetMapping("/threadLock")
    public String threadLock() 
        Object resourceA = new Object();
        Object resourceB = new Object();
        executor.submit(() -> 
            synchronized (resourceA) 
                try 
                    TimeUnit.SECONDS.sleep(1);
                 catch (InterruptedException e) 
                    e.printStackTrace();
                
                synchronized (resourceB) 
                
            
        );
        executor.submit(() -> 
            synchronized (resourceB) 
                try 
                    TimeUnit.SECONDS.sleep(1);
                 catch (InterruptedException e) 
                    e.printStackTrace();
                
                synchronized (resourceA) 
                
            
        );
        return "success";
    

上面在第一个线程中首先锁住了resourceA，第二个线程首先锁住了resourceB，然后等待1s的时候，第一个线程再去获取resourceB的锁，第二个线程再去获取resourceA的锁，这显然已经出现死锁了。

下面调用threadLock接口，使用dashboard查看下总体的情况：

看着貌似没有什么问题，下面在使用thread查看下总体线程的情况：

发现有两个 BLOCKED 状态的线程了。

这里说下线程的状态：

• RUNNABLE 运行中
• TIMED_WAITIN 调用了以下方法的线程会进入TIMED_WAITING：
  Thread#sleep()
  Object#wait() 并加了超时参数
  Thread#join() 并加了超时参数
  LockSupport#parkNanos()
  LockSupport#parkUntil()
• WAITING 当线程调用以下方法时会进入WAITING状态：
  Object#wait() 而且不加超时参数
  Thread#join() 而且不加超时参数
  LockSupport#park()
• BLOCKED 阻塞，等待锁

下面使用thread -b 让arthas 帮我们定位死锁的位置：

thread -b

这里直接定位到了两个线程有死锁，并给出了位置在JvmThreadController的122行，下面看下122行的代码：

真是其中一个死锁的位置，thread -b 也给出了两个线程的id 我们直接查看这两个线程的详情，也可以定位到死锁的位置。

喜欢的小伙伴可以关注我的个人微信公众号，获取更多学习资料！