Java线上问题排查神器——Arthas实战解析

背景

是不是在实际开发工作当中经常碰到自己写的代码在开发、测试环境行云流水稳得一笔,可一到线上就经常不是缺这个就是少那个反正就是一顿报错抽风似的,线上调试代码又很麻烦,让人头疼得抓狂;而且debug不一定是最高效的方法,遇到线上问题不能debug了怎么办。原先我们Java中我们常用分析问题一般是使用JDK自带或第三方的分析工具如jstat、jmap、jstack、 jconsole、visualvm、Java Mission Control、MAT等。但此刻的你没有看错,还有一款神器Arthas工具着实让人吃惊,可帮助程序员解决很多繁琐的问题,使得加班解决线上问题成为过去的可能性大大提高。

定义

Arthas是一个Java诊断工具,由阿里巴巴中间件团队开源,目前已在Java开发人员中被广泛采用。Arthas能够分析,诊断,定位Java应用问题,例如:JVM信息,线程信息,搜索类中的方法,跟踪代码执行,观测方法的入参和返回参数等等。并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法的出入参,异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率。简单的话:就是再不重启应用的情况下达到排查问题的目的。

特性

  • 仪表盘实时查看系统的运行状态。
  • OGNL表达式查看参数和返回值/例外,查看方法参数、返回值和异常。
  • 通过jad/sc/redefine实现在线热插拔。
  • 快速解决类冲突问题,定位类加载路径。
  • 快速定位应用热点和生成火焰图。
  • 支持在线诊断WebConsole。
  • Arthas对应用程序没有侵入(但对宿主机jvm有侵入),代码或项目中不需要引入jar包或依赖,因为是通过attach的机制实现的,我们的应用的程序和arthas都是独立的进程,arthas是通过和jvm底层交互来获取运行在其上的应用程序实时数据的,灵活查看运行时的值,这个和hickwall,jprofiler等监控软件的区别(JPofiler也有这样的功能,但是是收费的)动态增加aop代理和监控日志功能,无需重启服务,而且关闭arthas客户端后会还原所有增强过的类,原则上是不会影响现有业务逻辑的。
  • 对应用程序所在的服务器性能的影响,个别命令使用不当的话,可能会撑爆jvm内存或导致应用程序响应变慢,命令的输出太多,接口调用太频繁会记录过多的数据变量到内存里,比如tt指令,建议加 -n 参数 限制输出次数,sc * 通配符的使用不当,范围过大,使用异步任务时,请勿同时开启过多的后台异步命令,以免对目标JVM性能造成影响,一把双刃剑(它甚至可以修改jdk里的原生类),所以在线上运行肯定是需要权限和流程控制的。

使用场景

在日常开发中,当我们发现应用的某个接口响应比较慢,这个时候想想要分析一下原因,找到代码中耗时的部分,比较容易想到的是在接口链路的 IO 操作上下游打印时间日志,再根据几个时间点的日志算出耗时长的 IO 操作。这种方式没有问题,但是加日志需要发布,既繁琐又低效,这个时候可以引入一些线上 debug 的工具,arthas 就是很好的一种,除了分析耗时,还可以打印调用栈、方法入参及返回,类加载情况,线程池状态,系统参数等等,其实现原理是解析 JVM 在操作系统中的文件,大部分操作是只读的,对服务进程没有侵入性,因此可以放心使用。

实战

CPU占用高示例

创建一个springboot项目并打包成arthas-demo-1.0.jar,启动arthas-demo-1.0.jar

代码示例如下

package cn.itxs;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import java.util.UUID;
import java.util.concurrent.TimeUnit;

@SpringBootApplication
public class App 
{
    public static void main(String[] args) {
        SpringApplication.run(App.class,args);
        new Thread( () -> {
            while (true) {
                String str = UUID.randomUUID().toString().replaceAll("-", "");
            }
        },"cpu demo thread").start();

        new Thread( () -> {
            while (true) {
                String str = UUID.randomUUID().toString().replaceAll("-", "");
                try {
                    TimeUnit.MILLISECONDS.sleep(10);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        },"cpu with sleep thread").start();
    }
}

安装与使用

推荐方式

# 下载`arthas-boot.jar`这种也是官方推荐的方式
curl -O https://arthas.aliyun.com/arthas-boot.jar
# 启动arthas-boot.jar,必须启动至少一个 java程序,否则会自动退出。运行此命令会自动发现 java进程,输入需要 attach 进程对应的序列号,例如,输入1按回车则会监听该进程。
java -jar arthas-boot.jar
# 比如输入JVM (jvm实时运行状态,内存使用情况等)

CPU占用高示例

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/thread")
public class ThreadController {
    private Object obj1 = new Object();
    private Object obj2 = new Object();

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        new Thread(() -> {
            synchronized (obj1){
                try {
                    TimeUnit.SECONDS.sleep(10);
                } catch (InterruptedException e) {
                    synchronized (obj2){
                        System.out.printf("thread 1执行到此");
                    }
                }
            }
        },"thread 1").start();

        new Thread(() -> {
            synchronized (obj2) {
                synchronized (obj1){
                    System.out.printf("thread 2执行到此");
                }
            }
        },"thread 2").start();
        return "thread test";
    }
}

SpringBoot启动类

package cn.itxs;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class App 
{
    public static void main(String[] args) {
        SpringApplication.run(App.class,args);
    }
}
# 访问页面http://192.168.50.100:8080/cpu/test
# 仪表盘命令,通过上面我们可以发现线程ID为29也即是线程名称为“cpu demo thread”占用的cpu较高
dashboard
  • 第一部分时显示JVM中运行的所有线程:所在线程组,优先级,线程的状态,CPU的占有率,是否是后台进程等。
  • 第二部分显示的JVM内存的使用情况和GC的信息。
  • 第三部分是操作系统的一些信息和 Java版本号。
# 当前最忙的前N个线程 thread -b, ##找出当前阻塞其他线程的线程 thread -n 5 -i 1000 #间隔一定时间后展示,本例中可以看到最忙CPU线程为id=45,代码行数为19
thread -n 5 
# jad查看反编译的代码
jad cn.itxs.controller.CpuController

线程死锁示例

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;
import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/thread")
public class ThreadController {
    private Object obj1 = new Object();
    private Object obj2 = new Object();

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        new Thread(() -> {
            synchronized (obj1){
                try {
                    TimeUnit.SECONDS.sleep(10);
                } catch (InterruptedException e) {
                }
                synchronized (obj2){
                    System.out.println("thread 1执行到此");
                }
            }
        },"thread 1").start();
        try {
            TimeUnit.SECONDS.sleep(2);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        new Thread(() -> {
            synchronized (obj2) {
                synchronized (obj1){
                    System.out.println("thread 2执行到此");
                }
            }
        },"thread 2").start();
        return "thread test";
    }
}
# 启动SpringBoot演示程序,访问页面http://192.168.50.100:8080/thread/test
# 运行arthas,查看线程
thread
# 查看阻塞线程
thread -b
# jad反编译查看代码
jad --source-only cn.itxs.controller.ThreadController

线上修复热部署

准备一个有问题的java类

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.UUID;
import java.util.concurrent.TimeUnit;

@RestController
@RequestMapping("/hot")
public class HotController {

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        boolean flag = true;
        if (flag) {
            System.out.println("开始处理逻辑");
            throw new RuntimeException("出异常了");
        }
        System.out.println("结束流程");
        return "hot test";
    }
}

启动Spring Boot程序,访问页面http://192.168.50.94:8080/hot/test发现报错,当我们分析到这段程序出异常后,我们分析异常后进行线上代码修改不停机不重新发包的情况下的热更新,操作流程如下:

# 第一步:`jad命令` 将需要更改的文件先进行反编译,保存下来 ,编译器修改,-c 指定这个类的classloader的哈希值,–source-only只显示源码,最后是文件反编译之后的存放路径
jad --source-only cn.itxs.controller.HotController > /home/commons/arthas/data/HotController.java
# 我们将HotController.java中的throw new RuntimeException("出异常了")代码删掉,修改完后需要将类重新加载到JVM
# 第二步:`SC命令` 查找当前类是哪个classLoader加载的,首先,使用sc命令找到要修改的类.sc全称-search class, -d表示detail,主要是为了获取classLoader的hash值
sc -d *HotController | grep classLoader
classLoaderHash   6267c3bb #类加载器  编号    
# 第三步:`MC命令` 用指定的classloader重新将类在内存中编译
mc -c 6267c3bb /home/commons/arthas/data/HotController.java -d /home/commons/arthas/class
# 第四步:`redefine命令` 将编译后的类加载到JVM,参数是编译后的.class文件地址
redefine /home/commons/arthas/class/cn/itxs/controller/HotController.class

以上操作后再次访问一下页面http://192.168.50.94:8080/hot/test,发现异常没有了程序已经是我们修改正确后的,class文件替换成功,功能确实很强大。

上面我们是手工一步步执行,当然我们可以使用shell脚本串起来简单操作。

此外还可以安装Alibaba Cloud Toolkit热部署组件(一键retransform),热部署组件支持一键将编辑器中修改的 Java 源码快速编译,并更新到远端应用服务中,免去手动 dump、mc 的过程。此外,也可以一键还原 retransform 的类文件。

由于Arthas命令还是较复杂,Arthas-idea插件(部分命令可视化)是一个帮助生成命令的IDEA插件,使用文档:<u style="text-decoration: none; border-bottom: 1px solid rgb(68, 68, 68);">https://www.yuque.com/arthas-idea-plugin;</u>

安装基于Arthas实现的简单好用的热部署插件ArthasHotSwap可以一键生成热部署命令,提高我们线上维护的效率。

线上问题常见定位

watch(方法执行数据观测)

package cn.itxs.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

import java.util.ArrayList;
import java.util.List;
import java.util.Random;

@RestController
@RequestMapping("/watch")
public class WatchController {
    private static Random random = new Random();
    private int illegalArgumentCount = 0;

    @RequestMapping("/test")
    @ResponseBody
    public String test(){
        String res = null;
        try {
            int number = random.nextInt() / 10000;
            List<Integer> idStrs = this.getIdStr(number);
            res = printList(number, idStrs);
        }
        catch (Exception e) {
            System.out.println(String.format("illegalArgumentCount:%3d, ", this.illegalArgumentCount) + e.getMessage());
        }
        return res;
    }

    private List<Integer> getIdStr(int number) {
        if (number < 5) {
            ++this.illegalArgumentCount;
            throw new IllegalArgumentException("number is: " + number + ", need >= 5");
        }
        ArrayList<Integer> result = new ArrayList<Integer>();
        int count = 2;
        while (count <= number) {
            if (number % count == 0) {
                result.add(count);
                number /= count;
                count = 2;
                continue;
            }
            ++count;
        }
        return result;
    }

    private String printList(int number, List<Integer> primeFactors) {
        StringBuffer sb = new StringBuffer(number + "=");
        for (int factor : primeFactors) {
            sb.append(factor).append('*');
        }
        if (sb.charAt(sb.length() - 1) == '*') {
            sb.deleteCharAt(sb.length() - 1);
        }
        System.out.println(sb);
        return sb.toString();
    }
}

启动Spring Boot程序,通过Jmeter每秒访问一次http://192.168.50.100:8080/watch/test

# Arthas中的**watch**命令可以让我们能方便的观察到指定方法的调用情况,可以观察到返回值,入参,以及变量等。
# watch 全路径类名 方法名 观察表达式 -x 3  ,观察表达式匹配ognl表达式,观察的维度也比较多。
# 比如:watch cn.itxs.controller.WatchController printList "{params,returnObj}" -x 3
# 查看printList方法的入参和出参,-x表示的是遍历结果深度默认1,只会打印对象的堆地址,看不到具体的属性值,-x 2会打印结果的属性值的信息 -x 3会输出入参属性值和结果属性值
# -n 1只抓紧一次,由于我们这里是模拟一直请求的
watch cn.itxs.controller.WatchController printList '{params}' -n 1
# -x 表示的是遍历结果深度默认3
watch cn.itxs.controller.WatchController printList '{params}' -n 1 -x 3
# params[0]代表第一个参数
watch cn.itxs.controller.WatchController printList '{params[0]}' -n 1 -x 3
# 方法的返回值
watch cn.itxs.controller.WatchController getIdStr '{returnObj}' -n 1 -x 3
# 方法参数和返回值
watch cn.itxs.controller.WatchController getIdStr '{params,returnObj}' -n 1 -x 3
# 观察方法执行前后当前对象属性值
watch cn.itxs.controller.WatchController getIdStr 'target.illegalArgumentCount'
# 观察异常信息,观察表达式里增加throwExp就好了。如果增加-e 参数就能过滤掉非异常的监听了。
# 在观察表达式后面,我们可以增加条件表达式,例如按时间过滤:#cost>0.5,单位是毫秒,那么控制台输出来的都是耗时在0.5毫秒以上的方法调用
watch cn.itxs.controller.WatchController getIdStr '{params}' '#cost>0.5'
# 按条件过滤观察params[1].size>4:这里支持ognl表达式。下面例子的意思是:第二个参数(也就是List primeFactors),的size大于4的时候才观察入参。watch cn.itxs.controller.WatchController printList '{params}' 'params[1].size>4' -x 3

monitor(方法执行监控)

monitor结果包括如下

  • timestamp:时间戳
  • class:Java类
  • method:方法(构造方法、普通方法)
  • total:调用次数
  • success:成功次数
  • fail:失败次数
  • rt:平均RT
  • fail-rate:失败率
# -c :统计周期,默认值为10秒
monitor -c 10 cn.itxs.controller.WatchController getIdStr
# 在方法调用之前计算condition-express,方法后可带表达式
monitor -b -c 10 cn.itxs.controller.WatchController getIdStr

trace

# trace:方法内部调用路径,并输出方法路径上的每个节点上耗时
trace cn.itxs.controller.WatchController test -n 2
#包含jdk的函数--skipJDKMethod <value>  skip jdk method trace, default value true.默认情况下,trace不会包含jdk里的函数调用,如果希望trace jdk里的函数,需要显式设置--skipJDKMethod false。
trace --skipJDKMethod false cn.itxs.controller.WatchController test -n 2
# 调用耗时过滤,只会展示耗时大于10ms的调用路径,有助于在排查问题的时候,只关注异常情况
trace cn.itxs.controller.WatchController test '#cost > 1'

stack

# 输出当前方法被调用的调用路径,getIdStr是从test方法调用进来的
stack cn.itxs.controller.WatchController getIdStr -n 1
# 输出当前方法被调用的调用路径,条件表达过滤,第0个参数小于0,也可以根据执行时间来过滤,'#cost>1'
stack cn.itxs.controller.WatchController getIdStr 'params[0]<0' -n 1

tt

tt(TimeTunnel):方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测。对于一个最基本的使用来说,就是记录下当前方法的每次调用环境现场。

# 记录指定方法的每次调用环境现场
tt -t cn.itxs.controller.WatchController getIdStr 
# 列出所有调用记录
tt -l cn.itxs.controller.WatchController getIdStr
# 筛选调用记录
tt -s 'method.name=="getIdStr"'
# 查看调用信息
tt -i 1001
# 重新发起一次调用
tt -i 1001 -p

Web Console

# 启动时指定Linux的ip
java -jar arthas-boot.jar --target-ip 192.168.50.94

profiler

profiler 命令支持生成应用热点的火焰图。本质上是通过不断的采样,然后把收集到的采样结果生成火焰图。一般分析性能可以先通过Arthas profiler命令生成jfr文件;在本地通过jprofiler来分析jfr文件,定位谁在调用我。

# 启动profiler 默认情况下,生成的是cpu的火焰图,即event为cpu。可以用--event参数来指定
profiler start
# 获取已采集的sample的数量
profiler getSamples
# 查看profiler状态
profiler status
# 停止profiler 生成html格式结果,默认情况下,结果文件是html格式,也可以用--format参数指定;或者在--file参数里用文件名指名格式。比如--file /tmp/result.html
profiler stop --format html

通过浏览器查看arthas-output下面的profiler结果,<u style="text-decoration: none; border-bottom: 1px solid rgb(68, 68, 68);">http://192.168.50.100:3658/arthas-output/</u>

# profiler支持的events
profiler list
# 可以用--event参数指定要采样的事件,比如对alloc事件进入采样:
profiler start --event alloc
# 使用execute来执行复杂的命令
profiler execute 'start,framebuf=5000000'
# 生成 jfr格式结果;注意,jfr只支持在 start时配置。如果是在stop时指定,则不会生效。
profiler start --file /tmp/test.jfr
# 配置 include/exclude 来过滤数据
profiler start --include 'java/*' --include 'demo/*' --exclude '*Unsafe.park*'
# profiler执行 300 秒自动结束,可以用 -d/--duration 参数指定
profiler start --duration 300

其他功能

  • 提供Http API可以提供结构化的数据,支持更复杂的交互功能,比如特定应用场景的一系列诊断操作。Http API接口地址为:http://ip:port/api,必须使用POST方式提交请求参数。如POST http://127.0.0.1:8563/api
{
  "action": "exec",
  "requestId": "req112",
  "sessionId": "94766d3c-8b39-42d3-8596-98aee3ccbefb",
  "consumerId": "955dbd1325334a84972b0f3ac19de4f7_2",
  "command": "version",
  "execTimeout": "10000"
}
  • docker使用,很多时候,应用在docker里出现arthas无法工作的问题,是因为应用没有安装 JDK ,而是安装了 JRE 。如果只安装了 JRE,则会缺少很多JAVA的命令行工具和类库,Arthas也没办法正常工作,可以使用公开的JDK镜像和包管理软件来安装这两种方式在Docker里使用JDK。

    选择需要监控应用的进程编号,回车后Arthas会attach到目标进程上,并输出日志: docker exec -it arthas-demo /bin/sh -c "java -jar /opt/arthas/arthas-boot.jar" # 甚至我们可以直接把arthas放到容器镜像文件中:

  • Arthas Spring Boot Starter:应用启动后,spring会启动arthas,并且attach自身进程。
    <dependency> <groupId>com.taobao.arthas</groupId> <artifactId>arthas-spring-boot-starter</artifactId> <version>${arthas.version}</version> </dependency>
  • 非spring boot应用使用方式
<dependency>
            <groupId>com.taobao.arthas</groupId>
            <artifactId>arthas-agent-attach</artifactId>
            <version>${arthas.version}</version>
        </dependency>
        <dependency>
            <groupId>com.taobao.arthas</groupId>
            <artifactId>arthas-packaging</artifactId>
            <version>${arthas.version}</version>
        </dependency>
import com.taobao.arthas.agent.attach.ArthasAgent;

public class ArthasAttachExample {

    public static void main(String[] args) {
        ArthasAgent.attach();
    }
}
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,968评论 6 482
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,601评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 153,220评论 0 344
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,416评论 1 279
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,425评论 5 374
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,144评论 1 285
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,432评论 3 401
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,088评论 0 261
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,586评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,028评论 2 325
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,137评论 1 334
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,783评论 4 324
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,343评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,333评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,559评论 1 262
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,595评论 2 355
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,901评论 2 345

推荐阅读更多精彩内容