1.前言
背景
线上代码经常会出现CPU占用过高的情况,按以往经验我会使用top指令,进一步借助于jstack去查看具体信息从而进行问题排查,但基本上都逃不过需要重新发包的局面,即使是一个增量包,应用也需要短暂停启。后来运维大兄弟让我试一下Arthas,说是可以进行代码的热更新操作,正好来试一下。关于Arthas的安装与基础使用可以参考我这两篇:
Arthas安装与监听SpringBoot应用
Arthas基础指令使用说明
环境
JDK1.8
SPringBoot 2.2.2
Arthas
Linux
测试代码:
思路
Arthas
thread-b查看是否有阻塞线程
无阻寒
有阻寒
thread指令查最高占用的线程
threadid查看具体信息
信息不是很明确
信息明确指向具体方法
watch查看哪个Controller执行的具体方法
watch查看异常信息
jad反编译热更新
2.thread -b 查看是否有阻塞线程
thread -b, 找出当前阻塞其他线程的线程,执行完之后并未发现,说明该线程并非一直阻塞,一直执行的
[arthas@10999]$
thread
ngthreadfound!
btocking
Na
most
3.thread 查看占用最高的线程
当thread之后不跟参数时,显示当前全部线程信息,我觉得 thread -n 10,展示前10应该就够用,可根据实际需要自己决定。
下图可以很直观的看出,我们的应用瞬间占用了77%的CPU(这里我是发起请求瞬间,通过thread查看的,所以比较直观,生产环境应该只有阻塞,死锁这种状态才会比较直观)
GROUP
CPU
STATE
NATTING
http-n10-0.0.0.0-8080-Exec-3
false
alam
Trthattmncamooxconte
ttachlistener
talse
Fa15e
TFa13O
talse
folse
ylo
al5
NAITING
SianalDispatcher
RBMNSSSIEBEWS
42275
Fal5o
re
alse
trve
arthos-NettyHttpeLnetbootstrap-3.1
trie
aL气n
al5e
Halse
true
fa1u
TINENNATTTNG
ne
rthachell-`nover
arthos-shell-sorver
arthos-tiner
alse
re
A15日
TINEDNATTTNG
contalnre
http-nig-0.0.0.0-8080AcCgotor
False
rue
http-n1o-0.0.0.08080Blocoller
ralse
l30
htpnioa.a.e.nnannC1lom1Po11e
nc
http-n10-0.0.0.0-8080-exec-l
true
false
HE:Nt8:1:6.0.00.X
NAITING
a190
Lrug
false
http-n10-0.0.0.0-8080-xec
trve
http-n10-0.0.0.0-8080-exec-5
al5e
围头
htpnio0.0.0.00800.0x0c6
r
品
MAITING
httpn10-0.0.0.0-8880xec-7
true
f0l5e
http-n1o-0.0.0.0-8080excc
NAITING
true
falcn
0:0
http-ni0-0.0.0.0-0000-0x0c.9
Lre
NAITING
4.thread id 查看具体信息
在上一步基础上,我们进一步查看,thread 15(因为上面的ID=15)
[arthas@109]sthread15
"http-nio-0.0.0.08080exec-3
1015MtTiNGonjavautit.oct.o
atsun.mc.unafe.parknativeMehd
woltngmJbva.tt.
atjava.utt.oncurnt.kppt.au
abeudoare.ck.om
atjava.utt.ccurnt.nk
atorg.pache.tomcotut
atorg.apache.tomcat.
tjavautexuto)
tJavatL..u
tJavautLxo)
atorp.apace.tomat.ut.h
atjava.lang.Thread.run(Thread.java:748
他的大致意思就是:线程在等待一个条件从而继续执行,可以看到方法是在执行LinkedBlockingQueue.take方法时候,查看这个方法的API提示如下:
其中:AtomicInteger是保证高并发情况下的原子性,ReentrantLock标识可重入锁,都是JUC包下需要了解的这里不赘述,需要的百度了解下。
这段代码关键点就在于:notEmpty.await(),从队列中消费数据,当队列为空是,线程阻塞,所以我们大致知道现在出现的问题是线程阻塞,但是还是不知道具体哪行代码的问题。
如果能够明确知道这次更改了哪些代码,可以直接执行步骤6,不知道的话可以通过步骤5来定位问题。
5.watch 查看哪个Controller执行了代码
这个脚本可以检测一切通过DispatcherServlet匹配Handler的方法,也就是进入Controller的请求,如下:
Tartha3g1099wtthorg.k.h
PressQorCtrltctoabort
Affect(clascount,h
t2020081914:3651xcuc
handterdilandterhethocom.h
t川执行栏子
interceptors-nulL,
InterceptorList-adrrayListisEmpty-talses1ze-21.
intercoptorIndex-@Integerl.11.
207081914:365u
odfsthwaimamtemlog.m.
心
抵销担示
intercaptorlista@arraylistiseotyfaleze
interceptorIndex-@Integerl-1)
找到了对应的代码之后,我们来进一步观察异常信息,这里可能会有一个问题:就是我明明能通过日志去查看错误信息,为什么还需要这么繁琐的去操作。我的业务场景是:日志还是非常大的,刚捞到就被刷过去了,这时候定位日志不是很好操作,当然想捞下来日志肯定也是可以的,也很直观,我一般也都是去查看日志进行问题定位,这里也是提供一个思路。
6.watch 该方法异常信息
larthaso10999wotchcom.ta.ottti
PressQorctrlctoabort
Atiect(classcount:,mthodcou
t52020081914:44:16
@Integer[143931
ava.tang.utomeoryerrorLunabletocreatenenativethred
atjava.lang.thread.startotiethod)
atjava.ltang.Thread.start(Thread.java:717)
atcom.rthaontol
atsun.reflect.tivelethodcci)
atsun.rettect.atweethohccesom.c
usun.eed.betmmocm
atjava.ang.lctMthododja
ttQ0spmtbno.h
ub.mmtweolhbot.oem.
的6@心omccoboodomlo
的种地心心叶心..
叫.
10*mag0
ttorgpwgbwokeve
atong.3ptmgoetok.och
aoigsprlgramokwe
atorg.spngiuaorkeee.
atjayax,servlet.http.ttpslet.service(terlet.a3
torgprhngraidokabt
atjavax.serlethtt.tseyle.vice
DCapa.caatm.omoe
torg.gpadg.coam
.torg.puche.toatck
atong.apadhe.caatm.co
tong.epawhg.caalm.o
ton.spmgfoteokuob.tm
t03PaRk.
og.mdic.coolm.oatt
atoIgapdhc.otalm.oco
toR0sprhgtrangokweb.t
tbi:.pwrmtorkwe.e
如上,错误很直观的提示了出来,下面就可以修复解决了,这里我们也可以通过trace指令,查看执行时长:
返回信息如下,也可以看到错误信息,和每个方法执行的时长
7.jad 反编译热更新
在上面知道问题之后,我们就来定位问题就好了,
命令:jad 类全路径 方法名
此时代码就被反编译了,为了能够更改,所以我们需要输出为java文件
指令:jad com.arthas.controller.OrderController > /tmp/OrderController.java
即:jad 类全路径 方法名 > 存储路径/存储名称
然后到tmp路径下vi修改java文件即可,修改完成之后,查看对应的classloader为编译做准备
*OrderControlter
[arthas@13190]$sc
classLoaderHash
grep
17f052a3
classLoaderHash
17f052a3]/tmp/ordercontrolter
[arthas@13190]
lter.java-d/tmp
mC
Memorycompiler
Error
Compitation
exceptionmessage:
error
line:2,message
class,interface,orenum
expected
line:3,message:<identifierexpected
line:3,message:
interface,or
class
enumexpected
interface,
class
line:3,message:
expected
enum
or
line:4,message:
<identifier
expected
floating
line:4
literal
malformed
point
message:
line:4
interface,
enumexpected
class
or
message:
line:5,message
identifier>
expected
line:5,messageiclass
interface,orenumexpected
line:5,messageclass
interface.orenumexpected
lass
line:49message:c
classinterface,orenumexpected
pleasecheck$HoME/ogs/arthas/arthas.gored
但是这里编译出错了,官方提示:
@h
Collaborator
hengyunabccommentedon9May
eng
inal
mc不保证成功:https://arthas.gitee.io/c
hengyunabcclosedthison9May
labelon9May
hengyunabcaddedthe
dthequestion-answered
bluesaizcommentedon9May
Author
mc不保证成功:https://arthas.gitee.io/mc
哪些情况下会失败?可以说明一下吗
hengyunabccommentedon9May
Collaborator
eng
ina
mc不保证成功:https://arthas.gitee.io/mc
部些情况下会失败?可以说明一下吗
1.代码本身语法不对,比如用jad反译的结果就不一定合语法
2可能会有炎加发问照,编评本质上更我到法单元,也就.要我兴名,等,m不一定能我到所加忧奖
所以我们本地编译好class文件,上传上去是一样的
has]#cdrtmp
root@izwz91b8s2j56km66xiwxczrthas
tmp]#11
root@izwz91b8s2j56km66x1wxcz
total20268
4096Aug17:16yu
drwxr-xr-x3rootroot
Tr10tot870709017t
MTt1rootoot11993197Aug1609:26rth4549437912253186166rtha
4096Aug1915:42hsperfdataroot
drwxr-xr-x2rootroot
1101Aug1913:240
fw-r--r1rootroot
240rderController.class
TW-r--r--1
2208Aug1914:500rdercontrollerjava
rootroot
4996J181:Yt
drwx-----:3
rootroot
4096Aug1914:47tomcat96727260422836188
drwxr-xr-x3rootroot
4096Ag1809:23tomcat41558459236668
drwxr-xr-x3
rootroot
drwxr-Xr-x3
4096Aug1909:23tomcat.64675122976398050808
root
troot
4096Aug1819:14tomcat7985750289589352194
drwxr-Xr-x3
rootroot
4096Aug1910:13tomca48867396838449888880
drwxr-xr-x3rootroot
4096Aug1914:47toncat-docba
drwxr-xr-x2rootroot
编译前调用
更新前代码
更新后代码
编译指令
编译后调用三次
可以发现时间从6734.666529ms变成3ms左右,说明热更新的代码生效了
8.profile 绘制火焰图做后续分析
20200819-102814.svg(92 KB) 附件如下图:
1 人点赞
1