Java 诊断工具 Arthas-实操案例

举报
共饮一杯无 发表于 2022/08/16 09:45:15 2022/08/16
【摘要】 实操案例 排查函数调用异常通过curl 请求接口只能看到返回异常,但是看不到具体的请求参数和堆栈信息。shell@Alicloud:~$ curl http://localhost:61000/user/0{"timestamp":1655435063042,"status":500,"error":"Internal Server Error","exception":"java.lan...

实操案例

排查函数调用异常

通过curl 请求接口只能看到返回异常,但是看不到具体的请求参数和堆栈信息。

shell@Alicloud:~$ curl http://localhost:61000/user/0
{"timestamp":1655435063042,"status":500,"error":"Internal Server Error","exception":"java.lang.IllegalArgumentException","message":"id < 1","path":"/user/0"}

查看UserController的 参数/异常

在Arthas里执行:

watch com.example.demo.arthas.user.UserController * '{params, throwExp}'
  1. 第一个参数是类名,支持通配
  2. 第二个参数是函数名,支持通配 访问 curl http://localhost:61000/user/0 ,watch命令会打印调用的参数和异常

再次通过curl 调用可以在arthas里面查看到具体的异常信息。
image.png
把获取到的结果展开,可以用-x参数:

watch com.example.demo.arthas.user.UserController * '{params, throwExp}' -x 2

返回值表达式

在上面的例子里,第三个参数是返回值表达式,它实际上是一个ognl表达式,它支持一些内置对象:

  • loader
  • clazz
  • method
  • target
  • params
  • returnObj
  • throwExp
  • isBefore
  • isThrow
  • isReturn

比如返回一个数组:

watch com.example.demo.arthas.user.UserController * '{params[0], target, returnObj}'

条件表达式

watch命令支持在第4个参数里写条件表达式,比如:
当访问 user/1 时,watch命令没有输出
当访问 user/101 时,watch会打印出结果。
image.png

当异常时捕获

watch命令支持-e选项,表示只捕获抛出异常时的请求:

watch com.example.demo.arthas.user.UserController * "{params[0],throwExp}" -e

按照耗时进行过滤

watch命令支持按请求耗时进行过滤,比如:

watch com.example.demo.arthas.user.UserController * '{params, returnObj}' '#cost>200'

热更新代码

这个也是真的秀。
image.png
访问 http://localhost:61000/user/0 ,会返回500异常:

shell@Alicloud:~$ curl http://localhost:61000/user/0
{"timestamp":1655436218020,"status":500,"error":"Internal Server Error","exception":"java.lang.IllegalArgumentException","message":"id < 1","path":"/user/0"}

通过热更新代码,修改这个逻辑。

jad反编译UserController

jad --source-only com.example.demo.arthas.user.UserController > /tmp/UserController.java

jad反编译的结果保存在 /tmp/UserController.java文件里了。
再打开一个Terminal 窗口,然后用vim来编辑/tmp/UserController.java:

vim /tmp/UserController.java

比如当 user id 小于1时,也正常返回,不抛出异常:

@GetMapping(value={"/user/{id}"})
public User findUserById(@PathVariable Integer id) {
    logger.info("id: {}", (Object)id);
    if (id != null && id < 1) {
        return new User(id, "name" + id);
        // throw new IllegalArgumentException("id < 1");
    }
    return new User(id.intValue(), "name" + id);
    }

sc查找加载UserController的ClassLoader

[arthas@1266]$ sc -d *UserController | grep classLoaderHash
 classLoaderHash   19469ea2

classLoaderHash 是19469ea2,后面需要使用它。

mc

保存好/tmp/UserController.java之后,使用mc(Memory Compiler)命令来编译,并且通过-c或者–classLoaderClass参数指定ClassLoader:

mc --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader /tmp/UserController.java -d /tmp

[arthas@1266]$ mc --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader /tmp/UserController.java -d /tmp
Memory compiler output:
/tmp/com/example/demo/arthas/user/UserController.class
Affect(row-cnt:1) cost in 2879 ms.

也可以通过mc -c <classLoaderHash> /tmp/UserController.java -d /tmp,使用-c参数指定ClassLoaderHash:

mc -c 19469ea2 /tmp/UserController.java -d /tmp

redefine

再使用redefine命令重新加载新编译好的UserController.class:

[arthas@1266]$ redefine /tmp/com/example/demo/arthas/user/UserController.class
redefine success, size: 1, classes:
com.example.demo.arthas.user.UserController

热修改代码结果

redefine成功之后,再次访问 user/0 ,结果正常

shell@Alicloud:~$ curl http://localhost:61000/user/0
{"id":0,"name":"name0"}

动态更新应用Logger Level

查找UserController的ClassLoader

[arthas@1266]$ sc -d *UserController | grep classLoaderHash
 classLoaderHash   19469ea2

用ognl获取logger

ognl --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader ‘@com.example.demo.arthas.user.UserController@logger’

[arthas@1266]$ ognl --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader '@com.example.demo.arthas.user.UserController@logger'
@Logger[
    serialVersionUID=@Long[5454405123156820674],
    FQCN=@String[ch.qos.logback.classic.Logger],
    name=@String[com.example.demo.arthas.user.UserController],
    level=null,
    effectiveLevelInt=@Integer[20000],
    parent=@Logger[Logger[com.example.demo.arthas.user]],
    childrenList=null,
    aai=null,
    additive=@Boolean[true],
    loggerContext=@LoggerContext[ch.qos.logback.classic.LoggerContext[default]],
]

可以知道UserController@logger实际使用的是logback。可以看到level=null,则说明实际最终的level是从root logger里来的。

单独设置UserController的logger level

ognl --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader '@com.example.demo.arthas.user.UserController@logger.setLevel(@ch.qos.logback.classic.Level@DEBUG)'

再次获取UserController@logger,可以发现已经是DEBUG了。

修改logback的全局logger level

通过获取root logger,可以修改全局的logger level:

ognl --classLoaderClass org.springframework.boot.loader.LaunchedURLClassLoader '@org.slf4j.LoggerFactory@getLogger("root").setLevel(@ch.qos.logback.classic.Level@DEBUG)'

获取Spring Context,在获取 bean,再调用函数

7021ac47bd13ead7f0a50b41105983b.jpg

使用tt命令获取到spring context

tt即 TimeTunnel,它可以记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测。官方tt说明:https://arthas.aliyun.com/doc/tt.html

tt -t org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter invokeHandlerMethod

访问user/1,

 curl http://localhost:61000/user/1

可以看到tt命令捕获到了一个请求:
image.png
输入 q或者 Ctrl + C 退出上面的 tt -t命令。

使用tt命令从调用记录里获取到spring context

tt -i 1000 -w 'target.getApplicationContext()'

获取spring bean,并调用函数

tt -i 1000 -w ‘target.getApplicationContext().getBean(“helloWorldService”).getHelloMessage()’

结果如下:

[arthas@1266]$ tt -i 1000 -w 'target.getApplicationContext().getBean("helloWorldService").getHelloMessage()'
@String[Hello World]
Affect(row-cnt:1) cost in 1 ms.

排查HTTP请求返回401

请求接口没有权限的时候一般就返回401 Unauthorized
401通常是被权限管理的Filter拦截了,那么到底是哪个Filter处理了这个请求,返回了401?

跟踪所有的Filter函数

开始trace:

trace javax.servlet.Filter *

可以在调用树的最深层,找到AdminFilterConfig$AdminFilter返回了401

+---[3.806273ms] javax.servlet.FilterChain:doFilter()
|   `---[3.447472ms] com.example.demo.arthas.AdminFilterConfig$AdminFilter:doFilter()
|       `---[0.17259ms] javax.servlet.http.HttpServletResponse:sendError()

通过stack获取调用栈

上面是通过trace命令来获取信息,从结果里,我们可以知道通过stack跟踪HttpServletResponse:sendError(),同样可以知道是哪个Filter返回了401
执行:

stack javax.servlet.http.HttpServletResponse sendError 'params[0]==401'

访问可以看到如下堆栈信息:
image.png

查找Top N线程

查看所有线程信息

thread

查看具体线程的栈

查看线程ID 2的栈:

thread 2

查看CPU使用率top n线程的栈

thread -n 3

查看5秒内的CPU使用率top n线程栈

thread -n 3 -i 5000

查找线程是否有阻塞

thread -b

更多使用查看:
Github地址: https://github.com/alibaba/arthas
文档地址: https://arthas.aliyun.com/doc/

本文内容到此结束了,
如有收获欢迎点赞👍收藏💖关注✔️,您的鼓励是我最大的动力。
如有错误❌疑问💬欢迎各位大佬指出。

保持热爱,奔赴下一场山海。🏃🏃🏃

【版权声明】本文为华为云社区用户原创内容,转载时必须标注文章的来源(华为云社区)、文章链接、文章作者等基本信息, 否则作者和本社区有权追究责任。如果您发现本社区中有涉嫌抄袭的内容,欢迎发送邮件进行举报,并提供相关证据,一经查实,本社区将立刻删除涉嫌侵权内容,举报邮箱: cloudbbs@huaweicloud.com
  • 点赞
  • 收藏
  • 关注作者

评论(0

0/1000
抱歉,系统识别当前为高风险访问,暂不支持该操作

全部回复

上滑加载中

设置昵称

在此一键设置昵称,即可参与社区互动!

*长度不超过10个汉字或20个英文字符,设置后3个月内不可修改。

*长度不超过10个汉字或20个英文字符,设置后3个月内不可修改。