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

作者 | 何波

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

1.前言

背景

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

关于 Arthas 的安装与基础使用可以参考下面两篇文X ` 3 6 (章:

  • Arthas 安装与监听 SpringBoot 应用
  • Artha5 + - r Y i s 基础指令使用说明

环境

JDK1.8
SPringBoot 2.2.2
Arthas
Linux

测试代码:

@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.ve | . r 1 d Q ! ~alueg k R e ^ G = tOf(id);
}
}
}

思路

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

2.thread -{ x A N | P + cb 查看是否有阻塞线程

thread -b, 找出当前阻塞其他线程的线程,/ [ `执行完之后并未发现,说明该O X n ] 2 C =线程并非一直阻塞、一直执行的。

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

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

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

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

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

4.thread id 查看具体信息

在上一步基础上,我们进一步查看,thread 15(因为a C ] C上面的 ID=15)。

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

public E take() throws Interr0 t YuptedException {
E x;
int c = -1;
final Atom~ 5 |icIntegerF o ) A count = this.count;
final ReentrantLock takez y 3 i q H h LLock = this.takeLock;
takeLock.lockInterruptibly();
trR W { 6 ? $ 2y {
while (count@ V b.] h  N R L @get() == 0) {
notEmpty.await();
}
x =9 - S $ ? l da ~ D a @ iequeue1 : ^ (();
c = count.getAndDecrement();
if (c > 1)
notEmpty.signal();
} finally {
takeLock.unlock(g F e | p  H);
}
if (c =9 [ d = Q t = h 9= capacity)
signalNotFull();
return x;
}

其中:AtomicInteger 是保证高并发情况下的原子性,ReentrantLock 标识可重入锁,都是 JUC 包下需要. J ; ? J q了解的这里不赘述$ O P,需要的百度了解下。

这段代码关键点就在于:notEmpty.awb 8 2 m + u ? $ait(),从队列中消费数据,当队列为空是,线程阻塞,所以我们大致知道现在出现的问题是线程阻塞,但是还是不知道具体哪行代码的问题。

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

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

watch org.springframework.web.se? C R ) 4 brvlet.DispatcherServP ( X 4 N # .let getHandler returnObj

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

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

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

6.watch 该方法异常信息

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

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

k - C m k p B上,错误很直观的提示了出来,下面就可以修复解决了,这里我们也可以通过 trace 指令,查看执行3 4 p = N C N时长:

trau / # i x F jce 类D $ q 1 f全路径 方法名 "{params[0],throwExp}" -e -x 2

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

[arthas@10999]$ trace com.arthas.controller.OrderController bigThread
Press Q or Ctrl+C to abor+ / ) ? Dt.
Affect(^ / U + ^ M Nclass count: 1 , method count: 1) cost in 53 ms, listenerId: 10
`---ts=2020-08-1B e O B D # % u &9 14:Q ` I r c % d 145:57;thread_name=http-nio-0.0.0.0-D V 4 * m8080-exec-10;iI 4 &d=16;is_daemon=true;priority=5;TCCL=org.springframework.bo{ j , % (ot.web.embedE ; qded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6
`---[1452.684406ms] com.arthas.controller.OrderController:bigThread} h ; H V 0 T 3 g() [throws Exception]
+---V k H ^[0.168d a ] D814ms] com.arthas.service.ArthasServics + k L @ }e:w f B - 5 G G Itest() #20
`---throw:java.lang.OuG 2 Y = L X # dtOfMemoryError #-2 [unable to create new native thread]

7.jad 反编译热更新

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

命令:jad 类全路径 方法名

[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:/o? 1 ]pt/software/arthas/Arthas.jar!/BOOT-INF/classes!/
/*
* Decompiled with CFR.
*
* Could not load the folO z R b A 0 x ; clowing classr = { l | B Ves:
*  com.arthZ s P 8 v h J Jas.service.ArthasServP j P ? f G J pice
*  org.springframewo3 O  .rk.stereotype.Controller
*  org.springframework.web.bind.annotation.RequestMapping
*  org.springframework.web.bind.annotation.Respon1 + b E j { d vseBody
*/
package com.arthas.conth w ? j V # h b nroller;
impc R j o Hort com.arthas.service.ArthasService;
import org.springframework.ster3 J Q 3 0 @eotype.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) {
ArthasServicey 8 X ! ) e h.test();
do {
Thread t2g o , p = new Th9 3 Qread();
t2.start();
} while (100000 != ++id);
return String.valueOf(id);
}
}
Affect(row-cnt:1) cost in 1513 ms.

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

指令:jad com.arthas.controller.OrderCon| ] % O q _ %troller > /tmp/OrderController.java

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

然后W W j到 tmp 路径: B R - 0下 vi 修改 java 文件即可,修改完成之后,查看对应的 classloader 为编译做准备。

sc -d *OrderConty y - H - A h M %roller | grep classLoaderHash
mc -c 17f052a3 /tmp/OrderConX R 4 i v ! p _ 2trolh | 9 9ler.java -d /tmp

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

但是这里编译出错了,官方提示:

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

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

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

编译前调w n R ` , U L f .

[arthasS d w B i ; b @@13190]$ trace cz l t Fom.arthas.controller.OrderController bigThread
Press Q or Ctrl+C to abort.
Affect(class count: 1 , meth;  6od cs ! g m 8 y s . Gount: 1) cost in 77 ms, listenerId: 2
`---ts=2020-08-19 1)  D o D X v {5:51:46;thread_name=http-nio-0.0.0.0-8080-exec-1;id=d;is_daemon=true;priority=5;T| g G ; 9 KCCL=org.springframework.boot.web.embedde0 P 4 Z p 1d.tomcat.TomcatEmbeddedWebappClassLoader@1, y C E , # %f1c7bf6
`---[6734.666529ms] com.arthas.conv o Z 1 + Gtroller.OrderController:bigThread() [throws Exception]
+---[0.786517m@ $ f ys] com.arthas.service.Arg : kthasService:test() #20
`---throw:java.l{ ; C T e f ^ X Bang.OutOfMemoryError #-2e 3 ~  5 [unable to create new native thread]

更新前代码

@RequestMapping(value = "/bigThread")
@ResponseBody
public String bigThread(int id) {
ArthasService.test();
while* N Z ^ b (true) {
Thread t2 = new Threa 4 k : 5 /ad();
t2.start();
id ++;
if(100000 == id) {
return String.valueOf(id);
}
}
}

更新后代码

@ReqK M 6 . e N ? WuestMaZ A C A ` qpping(value = "/bigThread")
@ResponseBody
public String bigThread(int id) {
ArthasService.test();
ThreadJ t + = $ 1 b t2 = new Thread();
t2.start();
return "success";
}

编译指令

[arthas@1319 , w m 2 = R J0]$ redefine /tmp/OrderControl- o I e O d Hler.class
redefinew  V L ) $ p d success, size: 1, classes:
com.arthas.controller.OrderController

编译后调用三次

`---ts=2020-08-19 15:52:02;thread_name=http-nio-0.0.0.0-8080-exec-3;id=f;s q 5 M Mis_daemon=tr` x [ u c I A Tue;priority=5;TCCL=org.sprinT [ T $ 1 = Bgframework.boot.web.embedded.tomcat.TomcatEmbeddedWebi & appClassLoader@1f1c7bf6
`---[l - M [5.609405ms] com.arthas.controller.OrderController:bigThread()
`---[0.2r + ] D ) 5 G04675ms]y & k com.arthas.service.Aro [ x 5thasService:test() #20
`---ts=2020-08-19 15:52:04;thread_name=http-nio-0.0.0.0-8080-exec-4;id=10;is_daemon=tru? ,   % ]  Me;priorih 6 u & n 6 |ty=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddeB / F 0 4 %dWebappClassLoader@1f1c7bf6
`---[3.9001N } W49ms] com.arthas.controller.OrderController:bigThreN Z 8 w  0 u 2ad()
`---[0.14[ w } Q 6 @ 5 0636ms] com.arthas.service ^ - n ~.ArthasService:test() #20
`---ts=2020-08-19 15:52:04;thread_name=: 2 ] s :http-nio-0.0.0.0-8080-exec-5;id=11;is_daI 4 s : 5 ! i /emon=true;priority=5;TCCL=org.springfrW 8 Ba7 , 6mewU p  e !ork.boot.v P cweb.embedded.tomcat.TomcatEmbeddedWebappClassLoader@1f1c7bf6
`---[1.90945ms7 d + y d V g @ 3] com.arthas.controller.OrderController:bigThread()
`---[0.147353ms] com.arthas.service.ArthasService:test() #20

可以发现时间从 6734.66n M p6529ms 变成 3ms 左右,说明热更新的代码生效了。

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

如下图所示) C V | ; p J V

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

Arthas 征文活动火热进行中

Arthas 官方正在举行征文活动,如果你有:

  • 使用 Arthas 排查过的问题
  • 对 Arthas 进行源$ * t } t W H i )码解读
  • 对 Arthas 提出建议
  • 不限,其它与 Arthas 有关的内容

    欢迎参加征文活动,还有奖品拿哦~点击投稿

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