JMH 和 Arthas 定位问题的案例分享

最新推荐文章于 2024-11-09 17:15:55 发布

佩哥说Java

最新推荐文章于 2024-11-09 17:15:55 发布

阅读量141

点赞数

文章标签： java 开发语言后端

本文链接：https://blog.csdn.net/xupeiyan/article/details/123093580

版权

本文通过一个实际案例，展示了如何使用JMH进行性能基准测试，以及Arthas进行运行时诊断，定位到日志性能下降的原因。在测试中发现，`INCLUDE_LOCATION`配置导致了日志性能降低，通过Arthas的监控和反编译，揭示了该配置在Log4j2中的具体影响和性能开销。

摘要由CSDN通过智能技术生成

问题描述

为了能够让我后面的实例能够贯穿这两个工具的使用，我首先简单描述下我们在开发中遇到的实际的性能问题。然后再引出这两个性能工具的实际使用，看我们如何使用这两个工具成功定位到性能瓶颈的。

问题如下：为了能够支持丢失率，我们将原先log4j2 的Async+自定义Appender的方式进行了修正，把异步的逻辑放到了自己改版后的Appender中。但我们发现修改后日志性能要比之前Async+自定义Appender的方式下降不少。这里由于隐私原因我并没有用实际公司中的实例，这里我用了一种其他同样能够体现问题的方式。我们暂时先不给出具体的配置文件，先给出性能测试代码和结果

代码

package com.bryantchang.appendertest;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class AppenderTest {

    private static final String LOGGER_NAME_DEFAULT = "defaultLogger";
    private static final String LOGGER_NAME_INCLUDE = "includeLocationLogger";
    private static final Logger LOGGER = LoggerFactory.getLogger(LOGGER_NAME_INCLUDE);
    public static final long BATCH = 10000;

    public static void main(String[] args) throws InterruptedException {
        while(true) {
            long start, end;
            start = System.currentTimeMillis();
            for (int i = 0; i < BATCH; i++) {
                LOGGER.info("msg is {}", i);
            }
            end = System.currentTimeMillis();
            System.out.println("duration of " + LOGGER_NAME_INCLUDE +  " is " + (end - start) + "ms");
            Thread.sleep(1000);
        }
    }
}

代码逻辑及其简单，就是调用logger.info每次打印10000条日志，然后记录耗时。两者的对比如下

对比结果

从这两张图片中我们能够看到同样的逻辑，两个程序的耗时差距相差了数十倍，但看图片，貌似仅仅是logger的名称不一样。对上面的实验结果进行分析，我们可能会有两个疑问

上面的代码测试是否标准，规范
如果真的是性能问题，那么这两个代码到底在哪个方法上有了这么大的差距导致了最终的性能差异

下面这两个工具就分别来回答这两个问题

JMH简介

第一个问题就是，测试的方法是否标准。我们在编写代码时用的是死循环+前后“掐秒表”的方式。假如我们要再加个多线程的测试，我们还需要搞一个线程池，除了代码本身的逻辑还要关心测试的逻辑。我们会想，有没有一款工具能够将我们从测试逻辑中彻底解放出来，只需要关心我们需要测试的代码逻辑。JMH就是这样一款Java的测试框架。下面是JMH的官方定义

JMH 是一个面向 Java 语言或者其他 Java 虚拟机语言的性能基准测试框架

这里面我们需要注意的是，JMH所测试的方法约简单越好，依赖越少越好，最适合的场景就是，测试两个集合put，get性能，例如ArrayList与LinkedList的对比等，这里我们需要测试的是批量打一批日志所需要的时间，也基本符合使用JMH的测试场景。下面是测试代码，bench框架代码以及主函数。

待测试方法

public class LogBenchMarkWorker {

    private LogBenchMarkWorker() {}

    private static class LogBenchMarkWorkerInstance {
        private static final LogBenchMarkWorker instance = new LogBenchMarkWorker();
    }

    public static LogBenchMarkWorker getInstance() {
        return LogBenchMarkWorkerInstance.instance;
    }

    private static final String LOGGER_DEFAULT_NAME = "defaultLogger";
    private static final String LOGGER_INCLUDE_LOCATION = "includeLocationLogger";
    private static final Logger LOGGER = LoggerFactory.getLogger(LOGGER_DEFAULT_NAME);
    private static long BATCH_SIZE = 10000;

    public void logBatch() {
        for (int i = 0; i < BATCH_SIZE; i++) {
            LOGGER.info("msg is {}", i);
        }
    }
}

可以看到待测试方法非常简单，就是单批次一次性打印10000条日志的操作，所以并没有需要额外说明的部分。下面我们再来看benchmark部分。

public class LogBenchMarkMain {

    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @Fork(value = 1)
    @Threads(1)
    public void testLog1() {
        LogBenchMarkWorker.getInstance().logBatch();
    }

    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @Fork(va