记 Arthas 实现一次 CPU 排查与代码热更新

作者 | 何波

【Arthas 官方社区正在举行征文活动，参加即有奖品拿~ 点击投稿 】

1.前言

背景

线上代码经常会出现 CPU 占用过高的情况，按以往经验我会使用 top 指令，进一步借助于 jstack 去查看具体信息从而进行问题排查，但基本上都逃不过需要重新发包的局面，及时是一个增量包，应用也需要短暂停启。后来运维大兄弟让我试一下 Arthas，说是可以进行代码的热更新操作，正好来试一下。

关于 Arthas 的安装与基础使用可以参考下面两篇文章：

• Arthas 安装与监听 SpringBoot 应用
• Arthas 基础指令使用说明

环境

> JDK1.8

SPringBoot 2.2.2

Arthas

Linux

测试代码：

java

@RequestMapping(value = "/bigThread")

@ResponseBody

public String bigThread(int id) {

    ArthasService.test();

    while (true) {

        Thread t2 = new Thread();

        t2.start();

        id ++;

        if(100000 == id) {

            return String.valueOf(id);

        }

    }

}

思路

2.thread -b 查看是否有阻塞线程

thread -b, 找出当前阻塞其他线程的线程，执行完之后并未发现，说明该线程并非一直阻塞、一直执行的。

3.thread 查看占用最高的线程

当 thread 之后不跟参数时，显示当前全部线程信息，我觉得 thread -n 10，展示前 10 应该就够用，可根据实际需要自己决定。

下图可以很直观的看出，我们的应用瞬间占用了 77% 的 CPU(这里我是发起请求瞬间，通过 thread 查看的，所以比较直观，生产环境应该只有阻塞，死锁这种状态才会比较直观)。

4.thread id 查看具体信息

在上一步基础上，我们进一步查看，thread 15（因为上面的 ID=15）。

他的大致意思就是：线程在等待一个条件从而继续执行，可以看到方法是在执行 LinkedBlockingQueue.take 方法时候，查看这个方法的 API 提示如下：

java

public E take() throws InterruptedException {

    E x;

    int c = -1;

    final AtomicInteger count = this.count;

    final ReentrantLock takeLock = this.takeLock;

    takeLock.lockInterruptibly();

    try {

        while (count.get() == 0) {

            notEmpty.await();

        }

        x = dequeue();

        c = count.getAndDecrement();

        if (c > 1)

            notEmpty.signal();

    } finally {

        takeLock.unlock();

    }

    if (c == capacity)

        signalNotFull();

    return x;

}

其中：AtomicInteger 是保证高并发情况下的原子性，ReentrantLock 标识可重入锁，都是 JUC 包下需要了解的这里不赘述，需要的百度了解下。

这段代码关键点就在于：notEmpty.await()， 从队列中消费数据，当队列为空是，线程阻塞，所以我们大致知道现在出现的问题是线程阻塞，但是还是不知道具体哪行代码的问题。

如果能够明确知道这次更改了哪些代码，可以直接执行步骤 6，不知道的话可以通过步骤 5 来定位问题。

5.watch 查看哪个 Controller 执行了代码

java

watch org.springframework.web.servlet.DispatcherServlet getHandler returnObj

这个脚本可以检测一切通过 DispatcherServlet 匹配 Handler 的方法，也就是进入 Controller 的请求，如下：

找到了对应的代码之后，我们来进一步观察异常信息，这里可能会有一个问题：就是我明明能通过日志去查看错误信息，为什么还需要这么繁琐的去操作。我的业务场景是：日志还是非常大的，刚捞到就被刷过去了，这时候定位日志不是很好操作，当然想捞下来日志肯定也是可以的，也很直观，我一般也都是去查看日志进行问题定位，这里也是提供一个思路。

6.watch 该方法异常信息

java

watch 类全路径 方法名 "{params[0],throwExp}" -e -x 2

如上，错误很直观的提示了出来，下面就可以修复解决了，这里我们也可以通过 trace 指令，查看执行时长：

java

trace 类全路径 方法名 "{params[0],throwExp}" -e -x 2

返回信息如下，也可以看到错误信息，和每个方法执行的时长。

java

[arthas@10999]$ trace com.arthas.controller.OrderController bigThread

Press Q or Ctrl+C to abort.

Affect(class count: 1 , method count: 1) cost in 53 ms, listenerId: 10

`---ts=2020-08-19 14:45:57;thread_name=http-nio-0.0.0.0-8080-exec-10;id=16;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6

    `---[1452.684406ms] com.arthas.controller.OrderController:bigThread() [throws Exception]

        +---[0.168814ms] com.arthas.service.ArthasService:test() #20

        `---throw:java.lang.OutOfMemoryError #-2 [unable to create new native thread]

7.jad 反编译热更新

在上面知道问题之后，我们就来定位问题就好了。

命令：jad 类全路径 方法名

```java

[arthas@13190]$ jad com.arthas.controller.OrderController

ClassLoader:

+-org.springframework.boot.loader.LaunchedURLClassLoader@17f052a3

+-sun.misc.Launcher$AppClassLoader@3d4eac69

+-sun.misc.Launcher$ExtClassLoader@45f45fa1

Location:

file:/opt/software/arthas/Arthas.jar!/BOOT-INF/classes!/

/*

* Decompiled with CFR.

*

* Could not load the following classes:

* com.arthas.service.ArthasService

* org.springframework.stereotype.Controller

* org.springframework.web.bind.annotation.RequestMapping

* org.springframework.web.bind.annotation.ResponseBody

*/

package com.arthas.controller;

import com.arthas.service.ArthasService;

import org.springframework.stereotype.Controller;

import org.springframework.web.bind.annotation.RequestMapping;

import org.springframework.web.bind.annotation.ResponseBody;

@Controller

public class OrderController {

@RequestMapping(value={"/bigThread"})

@ResponseBody

public String bigThread(int id) {

ArthasService.test();

do {

Thread t2 = new Thread();

t2.start();

} while (100000 != ++id);

return String.valueOf(id);

}

}

Affect(row-cnt:1) cost in 1513 ms.

```

此时代码就被反编译了，为了能够更改，所以我们需要输出为 java 文件。

指令：jad com.arthas.controller.OrderController > /tmp/OrderController.java

即：jad 类全路径 方法名 > 存储路径/存储名称

然后到 tmp 路径下 vi 修改 java 文件即可，修改完成之后，查看对应的 classloader 为编译做准备。

java

sc -d *OrderController | grep classLoaderHash

mc -c 17f052a3 /tmp/OrderController.java -d /tmp

但是这里编译出错了，官方提示：

所以我们本地编译好 class 文件，上传上去是一样的。

编译前调用

java

[arthas@13190]$ trace com.arthas.controller.OrderController bigThread

Press Q or Ctrl+C to abort.

Affect(class count: 1 , method count: 1) cost in 77 ms, listenerId: 2

`---ts=2020-08-19 15:51:46;thread_name=http-nio-0.0.0.0-8080-exec-1;id=d;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6

    `---[6734.666529ms] com.arthas.controller.OrderController:bigThread() [throws Exception]

        +---[0.786517ms] com.arthas.service.ArthasService:test() #20

        `---throw:java.lang.OutOfMemoryError #-2 [unable to create new native thread]

更新前代码

java

@RequestMapping(value = "/bigThread")

@ResponseBody

public String bigThread(int id) {

    ArthasService.test();

    while (true) {

        Thread t2 = new Thread();

        t2.start();

        id ++;

        if(100000 == id) {

            return String.valueOf(id);

        }

    }

}

更新后代码

java

@RequestMapping(value = "/bigThread")

@ResponseBody

public String bigThread(int id) {

    ArthasService.test();

    Thread t2 = new Thread();

    t2.start();

    return "success";

}

编译指令

java

[arthas@13190]$ redefine /tmp/OrderController.class

redefine success, size: 1, classes:

com.arthas.controller.OrderController

编译后调用三次

```java

---ts=2020-08-19 15:52:02;thread_name=http-nio-0.0.0.0-8080-exec-3;id=f;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6 ---[5.609405ms] com.arthas.controller.OrderController:bigThread()

`---[0.204675ms] com.arthas.service.ArthasService:test() #20

---ts=2020-08-19 15:52:04;thread_name=http-nio-0.0.0.0-8080-exec-4;id=10;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6 ---[3.900149ms] com.arthas.controller.OrderController:bigThread()

`---[0.14636ms] com.arthas.service.ArthasService:test() #20

---ts=2020-08-19 15:52:04;thread_name=http-nio-0.0.0.0-8080-exec-5;id=11;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6 ---[1.90945ms] com.arthas.controller.OrderController:bigThread()

`---[0.147353ms] com.arthas.service.ArthasService:test() #20

```

可以发现时间从 6734.666529ms 变成 3ms 左右，说明热更新的代码生效了。

8.profile 绘制火焰图做后续分析

如下图所示：

Arthas 征文活动火热进行中

Arthas 官方正在举行征文活动，如果你有：

• 使用 Arthas 排查过的问题
• 对 Arthas 进行源码解读
• 对 Arthas 提出建议
• 不限，其它与 Arthas 有关的内容
  欢迎参加征文活动，还有奖品拿哦~ 点击投稿

“ 阿里巴巴云原生 关注微服务、Serverless、容器、Service Mesh 等技术领域、聚焦云原生流行技术趋势、云原生大规模的落地实践，做最懂云原生开发者的公众号。”