锋利的在线诊断工具——Arthas

导航

  • 前言
  • 火线告警,CPU飚了
  • 服务重启,迅速救火
  • 黑盒:无尽的猜测和不安
  • Arthas:锋利的Java诊断工具
  • 在线追踪Cpu占比高的代码段
  • 代码重构,星夜上线,稳了
  • 结语
  • 参考

肮脏的代码必须重构,但漂亮的代码也需要很多重构。

前言

有些代码在当初编写的时候是非常稳健的,但是随着数据量的不断增加,有些代码的“性能瓶颈”逐渐暴露出来。

这就可能会导致一些不可预知的线上事故。

那么,如何快速定位问题和处置问题就变得极其重要。

火线告警,CPU飚了

运维三板斧,重启、重装、重新买!

在多年的职业历练中,我养成了一个习惯——随时关注群里用户的反馈。

在一个阳光很好的午后,我和同事们正在加班加点的赶一个版本。

突然,群里有人反馈,线上的一个功能出现了问题,需要紧急处理。

锋利的在线诊断工具——Arthas

随即便是更多的业务对接群开始炸锅。

上个月因为数据库性能问题,已经出现了几次线上宕机的情况,被用户吐槽。
为此,我们做了大量的优化工作:

  • 慢sql优化
  • 去高频接口
  • 数据冷热分离
  • ...

今天再次遇到这样的问题,我们惊讶了几秒,然后很快恢复了镇定。

服务重启,迅速救火

我和业务团队的同事一边安抚用户的情绪,一边查看报警日志。

紧急着查看了报警日志,发现部署该业务接口的两台ecs CPU飙高了...

锋利的在线诊断工具——Arthas

再看数据库的CPU使用率并未报警。

当机立断,先重启一下服务。(PS:不要慌,不要慌,不要慌!)

大约两分钟之后,我们验证了可用性,并查看ecs和数据库各项指标,正常。

于是大家一一回复了用户群,对接群终于安静了。

黑盒:无尽的猜测和不安

路漫漫其修远兮,吾将上下而求索。

在这个时候,我已经开始了我的思考——是哪个功能或者哪句代码引发了ecs cpu标高呢?

过去,我们的思路总是先去查看网关日志,从时间点上排查可能导致性能问题的接口,然后逐渐深入。

然而,这个项目已经迭代3年多了,接口繁多,想快速定位无疑是大海捞针。

所以,对于这种黑盒般的问题,因为缺乏诊断工具,往往让我们陷入无尽的猜测和不安中。

是否有这样的工具帮助我快速定位到问题的代码呢?

Arthas:锋利的Java诊断工具

在这次的问题诊断中,我使用了Arthas来进行线上问题的诊断。

Arthas(阿尔萨斯)(是Alibaba开源的Java诊断工具,深受开发者喜爱。
在线排查问题,无需重启、动态跟踪Java代码、实时监控 JVM 状态。

Arthas支持JDK 6+,支持Linux/Mac/Windows,采用命令行交互模式,同时提供丰富的Tab自动补全功能,进一步方便进行问题的定位和诊断。

当你遇到以下类似问题而束手无策时,Arthas 可以帮助你解决:

  • 这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?
  • 我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?
  • 遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?
  • 线上遇到某个用户的数据处理有问题,但线上同样无法 debug,线下无法重现!
  • 是否有一个全局视角来查看系统的运行状况?
  • 有什么办法可以监控到 JVM 的实时运行状态?
  • 怎么快速定位应用的热点,生成火焰图?

官方教程

使用arthas-boot(推荐)

下载arthas-boot.jar,然后用java -jar的方式启动:

  • 执行该程序的用户需要和目标进程具有相同的权限。比如以admin用户来执行:sudo su admin && java -jar arthas-boot.jar 或 sudo -u admin -EH java -jar arthas-boot.jar。
  • 如果 attach 不上目标进程,可以查看~/logs/arthas/ 目录下的日志。
  • 如果下载速度比较慢,可以使用 aliyun 的镜像:java -jar arthas-boot.jar --repo-mirror aliyun --use-http
  • java -jar arthas-boot.jar -h 打印更多参数信息。
curl -O https://arthas.aliyun.com/arthas-boot.jar java -jar arthas-boot.jar 

锋利的在线诊断工具——Arthas
锋利的在线诊断工具——Arthas

选择应用java进程:

blog-webapp-0.0.1-SNAPSHOT.jar进程是第1个,则输入1,再输入回车/enter。Arthas 会 attach 到目标进程上,并输出日志:

[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER. * [1]: 27575 blog-webapp-0.0.1-SNAPSHOT.jar 1 [INFO] local lastest version: 3.7.2, remote lastest version: 4.0.2, try to download from remote. [INFO] Start download arthas from remote server: https://arthas.aliyun.com/download/4.0.2?mirror=aliyun [INFO] Download arthas success. [INFO] arthas home: /root/.arthas/lib/4.0.2/arthas [INFO] Try to attach process 27575 [INFO] Attach process 27575 success. [INFO] arthas-client connect 127.0.0.1 3658   ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.  /  O   |  .--. ''--.  .--'|  '--'  | /  O   '   .-' |  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-. |  | |  ||  |      |  |   |  |  |  ||  | |  |.-'    | `--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'  wiki       https://arthas.aliyun.com/doc tutorials  https://arthas.aliyun.com/doc/arthas-tutorials.html version    4.0.2 main_class pid        27575 time       2024-11-02 22:28:37.037  

在线追踪CPU占比高的代码段

从官方文档可以看到Arthas可以帮助定位到cpu飙高的代码段。

具体如何操作呢?

可以关注一下这个命令:thread

展示当前最忙的前 N 个线程并打印堆栈(https://arthas.aliyun.com/doc/thread.html)

$ thread -n 3 "C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms  "arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE     at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method)     at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466)     at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199)     at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122)     at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82)     at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18)     at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111)     at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108)     at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385)     at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)     at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264)     at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)     at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)     at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)     at java.base@11.0.7/java.lang.Thread.run(Thread.java:834)   "VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms  

上面展示了cpu最高的三个线程。

通过这种方式我们就可以定位到到cpu飙高的代码段。(这里是示例,具体项目案例这里就不粘贴了~)

代码重构,星夜上线,稳了

通过这个工具相对比较精准的定到了导致cpu飙高的代码片段。

进一步进入代码发现,是因为这里有一个接口,包含了一个分页查询,在返回数据的时候,需要对数据进行了包装。
这里的代码逻辑如下:
遍历循环,查询数据库,然后计算了一个数据赋值给某个扩展字段。

如果是普通接口,数据量不大,也不会有什么问题。

但是,这里是IM群里会话接口,在某一个瞬间(比如,大量用户同时登录软件),拉去IM群里的会话列表,所以这里的代码逻辑就会导致cpu飙高。

Note: 本项目类似企业微信的IM群聊,但是没有使用本地数据库,聊天数据从接口实时拉取。

于是,快速重构了这段代码,星夜上线。

至此,该问题就解决了。

结语

哪有什么岁月静好,总有人在看不到地方为你负重前行。

所谓的"技术好",不是单纯的卖弄技术,而是能够针对灵活多变的场景,恰到好处的运用技术。

活到老,学到老。

在这个过程中,我们要保持对技术的敬畏,不断学习,不断进步。

善于使用工具来解决问题,让我们的生活更加美好。

这里笔者只根据个人多年的工作经验,一点点思考和分享,抛砖引玉,欢迎大家怕批评和斧正。

参考

锋利的在线诊断工具——Arthas

发表评论

相关文章