java异常-性能分析

发表于 2018-08-13 更新于 2022-05-28 分类于 java 阅读次数： Waline：本文字数： 4.4k 阅读时长 ≈ 4 分钟

遇到一个问题，Java里处理异常会有多慢。然后就自测+Google

曾经在给一个业务系统增加限流功能，使用的限流组件在流量超过阈值时，会直接抛异常，异常导致 CPU 占用率飙升。第一次遇到这样的情况，让我们不得不思考，异常怎么会对性能造成这么大的影响？
在消除了这些异常之后，代码运行速度与以前相比大幅提升。这让我们产生一种猜测，就是在代码里面使用异常会带来显著的性能开销。因为异常是错误情况处理的重要组成部分，摒弃是不太可能的,所以我们需要衡量异常处理对于性能影响，我们可以通过一个实验看看异常处理的对于性能的影响。

Java在处理异常时会取操作栈中引用的异常对象
建立一个异常对象，是建立一个普通Object耗时的约20倍（实际上差距会比这个数字更大一些，因为循环也占用了时间，追求精确的读者可以再测一下空循环的耗时然后在对比前减掉这部分），而抛出、接住一个异常对象，所花费时间大约是建立异常对象的4倍。

下面的数据3个为一组，分别是 异常不作处理花费的时间，异常只抛出花费的时间，异常打印到日志花费的时间
用时 0.062 s
用时 0.094 s
用时 0.782 s

用时 0.046 s
用时 0.094 s
用时 0.75 s

用时 0.047 s
用时 0.078 s
用时 0.673 s

可以看到异常不做处理花费的时间最少，异常抛出花费的时间是不处理异常的2倍左右，把异常用slf4j+logback打印到日志的时间是不处理异常的10倍左右。
处理异常花费时间原因是 java处理异常时，会把栈中涉及到的所有堆栈信息取出。然后打印到日志，特别耗费 CPU 内存 IO (待详细测试)。

catch 中不做任何事情

public class ExceptionTest {
    public static void main(String[] args) {
        doExTest();
        doExTest();
    }

    private static void doExTest() {
        long start = System.nanoTime();
        for (int i=0; i<100000; ++i) {
            try {
                throw new RuntimeException("" + Math.random());
            } catch (Exception e) {
            }
        }
        System.out.println("time: " + (System.nanoTime() - start));
    }
}

time: 365218274
time: 224583244

第一次 doExTest 只是起到预热的作用，我们以第二次 doExTest 的时间为准。10 万次请求，平均每次请求耗时 2245 纳秒，也就是 0.002 毫秒，速度还是很快的。

catch 中输出异常到日志

public class ExceptionTest {
    private static final Logger logger = LoggerFactory.getLogger(ExceptionTest.class);

    public static void main(String[] args) {
        doExTest();
        doExTest();
    }

    private static void doExTest() {
        long start = System.nanoTime();
        for (int i=0; i<100000; ++i) {
            try {
                throw new RuntimeException("" + Math.random());
            } catch (Exception e) {
                logger.error("fuck", e);
            }
        }
        System.out.println("time: " + (System.nanoTime() - start));
    }
}

time: 13454674590
time: 9891780450

10 万次请求，平均每次请求耗时 98917 纳秒，大约 0.1 毫秒，比“不输出异常”的时候，慢了 50 倍。输出日志如此耗费性能，那么 logger.error 这一句做了什么事儿呢？

根据过滤规则，判断是否要输出日志
获取异常堆栈
拼接日志字符串，输出日志到文件


import org.junit.Test;

/**
 * @author: weikeqin.cn@gmail.com
 * @create: 2018-08-13 20:35
 **/
public class ExceptionTest {

    public ExceptionTest() {
    }

    /**
     * @return
     * @throws Exception
     */
    public boolean testEx1() throws Exception {
        boolean ret = true;
        try {
            ret = testEx2();
        } catch (Exception e) {
            System.out.println("testEx1, catch exception");
            ret = false;
            throw e;
        } finally {
            System.out.println("testEx1, finally; return value=" + ret);
            return ret;
        }
    }

    /**
     * @return
     * @throws Exception
     */
    public boolean testEx2() throws Exception {
        boolean ret = true;
        try {
            ret = testEx3();
            if (!ret) {
                return false;
            }
            System.out.println("testEx2, at the end of try");
            return ret;
        } catch (Exception e) {
            System.out.println("testEx2, catch exception");
            ret = false;
            throw e;
        } finally {
            System.out.println("testEx2, finally; return value=" + ret);
            return ret;
        }
    }

    /**
     * @return
     * @throws Exception
     */
    public boolean testEx3() throws Exception {
        boolean ret = true;
        try {
            int b = 12;
            int c;
            for (int i = 2; i >= -2; i--) {
                c = b / i;
                System.out.println("i=" + i);
            }
            return true;
        } catch (Exception e) {
            System.out.println("testEx3, catch exception");
            ret = false;
            throw e;
        } finally {
            System.out.println("testEx3, finally; return value=" + ret);
            return ret;
        }
    }


    /**
     * 测试异常
     */
    @Test
    public void testException() {
        try {
            testEx1();
        } catch (Exception e) {
            e.printStackTrace();
        }
    }


    /**
     * @param i
     * @param level
     */
    public void doTest(int i, int level) {
        if(level < maxLevel){
            try {
                doTest(i, ++level);
            } catch (Exception e) {
                // e.printStackTrace();
                throw new RuntimeException("UUUPS", e);
            }
        }else{
            if(i > 1){
                throw new RuntimeException("Ups".substring(0, 3));
            }
        }
    }

    public long maxLevel = 20;

    /**
     * @param args
     */
    public static void main(String[] args) {
        ExceptionTest test = new ExceptionTest();
        long start = System.currentTimeMillis();
        int count = 10000;
        for (int i = 0; i < count; i++) {
            try {
                test.doTest(2, 0);
            } catch (Exception e) {
                //e.printStackTrace();
            }
        }
        long diff = System.currentTimeMillis() - start;
        System.out.println(String.format("Average time for invocation: %s", (1.0 * diff / count)));
    }


}

public class Test {
    public static void main ( String[] args ) {
        outerTry( args );
        innerTry( args );       
    }

    private static void outerTry ( String[] args ) {
        try {
            for ( String arg : args ) {
                tryMethod();
            }
        }catch ( Exception e ){
            catchMethod();
        }

    }

    private static void innerTry ( String[] args ) {
        for ( String arg : args ) {
            try{
                tryMethod();
            }catch ( Exception e ){
                catchMethod();
            }
        }
    }

    private static void tryMethod () { }

    private static void catchMethod () { }
}

更新中..

References

[1] Java 进阶：异常影响性能吗？
[2] 【译】JAVA 异常对于性能的影响
[3] java 异常－性能及实现机制分析
[4] 系统性能调优(6)—-Java异常处理性能优化
[5] Java Exception性能问题