目录
Arthas 是一款线上监控诊断产品,通过全局视角实时查看应用 load、内存、gc、线程的状态信息,并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法调用的出入参、异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率。
官方推荐的是可以直接下载jar包,然后在JDK环境下启动boot应用即可。
- curl -O https://arthas.aliyun.com/arthas-boot.jar
- java -jar arthas-boot.jar
一般我们使用arthas都是为了排查某个服务的问题,所以需要在启动命令后追加服务的进程PID
例如使用:ps -ef|grep java 查询目标PID为8,然后执行java -jar arthas-boot.jar 8 即可。
看到client链接后出现这个界面后就可以直接使用了。
可以查看到CPU、内存、GC、运行环境等信息。
查看当前目标进程下的线程信息。
-n 5:指定最忙的前 5 个线程并打印堆栈
解析请求方法内部调用路径,并输出方法路径上的每个节点上耗时,默认会过滤JDK方法和耗时。
如果trace出来的总耗时和明细耗时对不起来。其他未展示出来的耗时包括JDK方法耗时,GC耗时,或者非函数调用的指令消耗如i++等命令
--skipJDKMethod false 默认情况下,trace 不会包含 jdk 里的函数调用,如果希望 trace jdk 里的函数,需要显式设置。
--exclude-class-pattern
参数可以排除掉指定的类--listenerId 根据id动态trace
- [arthas@7]$ trace com.demo.dismantleBill.ChainDismantleBillGrpcService addDismantleBill
- Press Q or Ctrl+C to abort.
- Affect(class count: 2 , method count: 2) cost in 523 ms, listenerId: 2
- `---ts=2022-08-27 16:20:57;thread_name=grpc-executor-grpc-bill-server--6-91;id=fa;is_daemon=true;priority=5;TCCL=org.springframework.boot.loader.LaunchedURLClassLoader@3830f1c0
- `---[888.577986ms] com.demo.dismantleBill.ChainDismantleBillGrpcService$$EnhancerBySpringCGLIB$$d8d642cf:addDismantleBill()
- `---[99.91% 887.774586ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
- `---[99.75% 885.517295ms ] com.demo.service.dismantleBill.ChainDismantleBillGrpcService:addDismantleBill()
- +---[0.01% 0.071908ms ] com.demo.common.Common$ResponseHeader:newBuilder() #59
- +---[0.00% 0.016074ms ] com.demo.bill.ChainDismantleBillServiceOuterClass$chainDismantleBillRequest:getBill() #62
- +---[0.01% 0.055176ms ] com.demo.util.ProtoConvertUtil:convertDismantleBillFromRequest() #62
- +---[0.00% 0.015164ms ] com.demo.model.ChainBill:getSourceTemplateID() #63
- +---[0.00% 0.015551ms ] org.apache.commons.lang3.StringUtils:isNotEmpty() #63
- +---[0.00% 0.01578ms ] com.google.common.base.Preconditions:checkArgument() #63
- +---[0.00% 0.010558ms ] com.demo.bill.ChainDismantleBillServiceOuterClass$chainDismantleBillRequest:getDetailList() #64
- +---[0.00% 0.008282ms ] org.apache.commons.lang3.StringUtils:isNotEmpty() #66
- +---[0.00% 0.008602ms ] com.google.common.base.Preconditions:checkArgument() #66
- +---[0.00% 0.006723ms ] com.demo.bill.ChainDismantleBillServiceOuterClass$chainDismantleBillRequest:getDetailList() #67
- +---[9.90% 87.68764ms ] com.demo.service.dismantleBill.ChainDismantleBillGrpcService:attachInfosForDetail() #67
- +---[0.00% 0.015263ms ] com.demo.util.CommonUtils:notEmpty() #69
- +---[56.25% 498.118919ms ] com.demo.service.dismantleBill.ChainDismantleBillService:commonCheckBeforeSave() #70
- +---[24.63% 218.087678ms ] com.demo.service.dismantleBill.ChainDismantleBillService:insertDismantleBill() #71
- +---[0.00% 0.008805ms ] com.demo.commons.errorcode.BasicErrorCode:getCode() #73
- +---[0.00% 0.022887ms ] com.demo.common.Common$ResponseHeader$Builder:setCode() #73
- +---[0.00% 0.007032ms ] com.demo.commons.errorcode.BasicErrorCode:isSuccess() #73
- +---[0.00% 0.010759ms ] com.demo.common.Common$ResponseHeader$Builder:setSuccess() #73
- +---[0.00% 0.007096ms ] com.demo.commons.errorcode.BasicErrorCode:getMessage() #73
- +---[0.00% 0.028821ms ] com.demo.common.Common$ResponseHeader$Builder:setMsg() #73
- +---[0.00% 0.016511ms ] com.demo.common.Common$ResponseHeader$Builder:build() #81
- +---[8.78% 77.776133ms ] io.grpc.stub.StreamObserver:onNext() #81
- `---[0.01% 0.050585ms ] io.grpc.stub.StreamObserver:onCompleted() #82
下面示例可以看出不加--skipJDKMethod false时无JDK相关方法调用信息
watch class路径 method名称
express:默认值:{params, target, returnObj},指定输出结果包括参数和调用,返回结果
x:指定输出结果的属性遍历深度,默认为 1最大是4,该参数决定打印入参和结果的对象深度
location:AtEnter,AtExit,AtExceptionExit 分别对应函数入口,函数正常 return,函数抛出异常。
也就是说当location输出为AtExit时说明方法正常执行返回结果,当location输出为AtExceptionExit时说明方法抛出异常。
- //观察queryPurchaseBillDetai方法的返回结果 结果属性便利深度为2
- watch com.demo.purchasebill.PurchaseBillService queryPurchaseBillDetail "{returnObj}" -x 2
- Press Q or Ctrl+C to abort.
- Affect(class count: 1 , method count: 1) cost in 408 ms, listenerId: 14
- method=com.demo.purchasebill.PurchaseBillService.queryPurchaseBillDetail location=AtExit
- ts=2022-08-22 14:35:35; [cost=53.526978ms] result=@ArrayList[
- @JSONObject[
- @String[msg]:@String[??????],
- @String[traceID]:@String[20220822143535173rygx8b],
- @String[code]:@String[000],
- @String[data]:@JSONObject[isEmpty=false;size=7],
- @String[success]:@Boolean[true],
- @String[ms]:@Long[54],
- @String[host]:@String[supplychain-api-v1-6c5b8459b4-xt82f],
- @String[traceMD5]:null,
- ],
- ]
- //观察queryPurchaseBillDetai方法的返回结果 结果属性便利深度为3
- watch com.hualala.supplychain.service.purchasebill.PurchaseBillService queryPurchaseBillDetail "{returnObj}" -x 3
- Press Q or Ctrl+C to abort.
- Affect(class count: 1 , method count: 1) cost in 441 ms, listenerId: 16
- method=com.hualala.supplychain.service.purchasebill.PurchaseBillService.queryPurchaseBillDetail location=AtExit
- ts=2022-08-22 14:37:28; [cost=160.980696ms] result=@ArrayList[
- @JSONObject[
- @String[msg]:@String[??????],
- @String[traceID]:@String[d6bb0540-6dec-4cc7-a913-edb2c6b46719],
- @String[code]:@String[000],
- @String[data]:@JSONObject[
- @String[purchaseIsShowOrder]:@String[0],
- @String[records]:@JSONArray[isEmpty=false;size=1],
- @String[record]:@JSONObject[isEmpty=false;size=119],
- @String[existPendingPaymentRecord]:@String[0],
- @String[nineDragonsPay]:@String[0],
- @String[sumInfo]:@JSONObject[isEmpty=false;size=41],
- @String[giftInfos]:@JSONArray[isEmpty=true;size=0],
- ],
- @String[success]:@Boolean[true],
- @String[ms]:@Long[162],
- @String[host]:@String[supplychain-api-v1-6c5b8459b4-xt82f],
- @String[traceMD5]:null,
- ],
- ]
通过上面x参数为2和3的两次watch结果可以看出x参数影响的时输出对象属性的深度。
上面这个watch结果可以看到result内包含两个对象,分别是入参和返回值。
watch虽然很方便和灵活,但是太过于实时,如果能记录下请求的入参信息进行重复模拟的话对于线上debug排查是最方便的。于是乎,TimeTunnel 命令就诞生了,这个命令用于记录当前方法的每次调用环境现场,然后可以进行模拟重复调用。
-t 记录下指定类方法的每次执行情况
-n 指定你需要记录的次数,当达到记录次数时 Arthas 会主动中断 tt 命令的记录过程,避免人工操作无法停止的情况。这个其实很有用,特别是当排查的方法并发量大的时候手动停止可能来不及操作。
-i 指定模拟重发请求的index,index来自于-t执行后的结果。
下面的示例记录指定updateDismantleBill方法的请求信息,-n参数指定记录2次就退出。
有了上面记录的index,就可以进行请求模拟重放。
需要注意的是,tt -i 模拟请求无法携带ThreadLocal的信息,这些信息在请求时无法保存下来。另外如果方法本身发生了代码变更,得到的结果可能也不是一样的,要想得到准确实时的请求结果还是得适用watch观察。