1. 首页
  2. jvm实践

异常栈信息不见了之JVM参数OmitStackTraceInFastThrow

问题描述

某天收到生产环境error日志告警(对error.log监控,超过一定大小就会给开发人员发送告警短信)。但是tail查看最新的异常信息只有这些,好忧伤:

  ... ...
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    ... ...

后来有个同事从error.log前面开始看起,能看到完整的异常栈信息,大致如下,这样的信息就能够准确的定位问题:

  ... ...
    java.lang.NullPointerException
        at com.afei.juc.WithNPESimulate.run(NPEMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    java.lang.NullPointerException
        at com.afei.juc.WithNPESimulate.run(NPEMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    ... ...

那么前面那段只有简单的java.lang.NullPointerException,没有详细异常栈信息的原因是什么呢?这需要从一个JVM参数说起。

原因分析

JVM中有个参数:OmitStackTraceInFastThrow,字面意思是省略异常栈信息从而快速抛出,那么JVM是如何做到快速抛出的呢?JVM对一些特定的异常类型做了Fast Throw优化,如果检测到在代码里某个位置连续多次抛出同一类型异常的话,C2会决定用Fast Throw方式来抛出异常,而异常Trace即详细的异常栈信息会被清空。这种异常抛出速度非常快,因为不需要在堆里分配内存,也不需要构造完整的异常栈信息。相关的源码的JVM源码的graphKit.cpp文件中,相关源码如下:

  //------------------------------builtin_throw----------------------------------
    void GraphKit::builtin_throw(Deoptimization::DeoptReason reason, Node* arg) {
      bool must_throw = true;

      ... ...
      // 首先判断条件是否满足
      // If this particular condition has not yet happened at this
      // bytecode, then use the uncommon trap mechanism, and allow for
      // a future recompilation if several traps occur here.
      // If the throw is hot(表示在代码某个位置重复抛出异常), try to use a more complicated inline mechanism
      // which keeps execution inside the compiled code.
      bool treat_throw_as_hot = false;

      if (ProfileTraps) {
        if (too_many_traps(reason)) {
          treat_throw_as_hot = true;
        }
        // (If there is no MDO at all, assume it is early in
        // execution, and that any deopts are part of the
        // startup transient, and don't need to be remembered.)

        // Also, if there is a local exception handler, treat all throws
        // as hot if there has been at least one in this method.
        if (C->trap_count(reason) != 0
            && method()->method_data()->trap_count(reason) != 0
            && has_ex_handler()) {
            treat_throw_as_hot = true;
        }
      }

      // If this throw happens frequently, an uncommon trap might cause
      // a performance pothole.  If there is a local exception handler,
      // and if this particular bytecode appears to be deoptimizing often,
      // let us handle the throw inline, with a preconstructed instance.
      // Note:   If the deopt count has blown up, the uncommon trap
      // runtime is going to flush this nmethod, not matter what.
      // 这里要满足两个条件:1.检测到频繁抛出异常,2. OmitStackTraceInFastThrow为true,或StackTraceInThrowable为false
      if (treat_throw_as_hot
          && (!StackTraceInThrowable || OmitStackTraceInFastThrow)) {
        // If the throw is local, we use a pre-existing instance and
        // punt on the backtrace.  This would lead to a missing backtrace
        // (a repeat of 4292742) if the backtrace object is ever asked
        // for its backtrace.
        // Fixing this remaining case of 4292742 requires some flavor of
        // escape analysis.  Leave that for the future.
        ciInstance* ex_obj = NULL;
        switch (reason) {
        case Deoptimization::Reason_null_check:
          ex_obj = env()->NullPointerException_instance();
          break;
        case Deoptimization::Reason_div0_check:
          ex_obj = env()->ArithmeticException_instance();
          break;
        case Deoptimization::Reason_range_check:
          ex_obj = env()->ArrayIndexOutOfBoundsException_instance();
          break;
        case Deoptimization::Reason_class_check:
          if (java_bc() == Bytecodes::_aastore) {
            ex_obj = env()->ArrayStoreException_instance();
          } else {
            ex_obj = env()->ClassCastException_instance();
          }
          break;
        }
        ... ...
    }

说明:OmitStackTraceInFastThrowStackTraceInThrowable都默认为true,所以条件(!StackTraceInThrowable || OmitStackTraceInFastThrow)为true,即JVM默认开启了Fast Throw优化。如果想关闭这个优化,很简单,配置-XX:-OmitStackTraceInFastThrowStackTraceInThrowable保持默认配置-XX:+OmitStackTraceInFastThrow即可。

另外,根据这段源码的switch .. case ..部分可知,JVM只对几个特定类型异常开启了Fast Throw优化,这些异常包括:

  • NullPointerException
  • ArithmeticException
  • ArrayIndexOutOfBoundsException
  • ArrayStoreException
  • ClassCastException

问题验证

为了验证这个问题,笔者写了下面这段代码:

  /**
     * @author afei
     * @version 1.0.0
     * @since 2018年06月08日
     */
    class WithNPE extends Thread{

        private static int count = 0;

        @Override
        public void run() {
            try{
                System.out.println(this.getClass().getSimpleName()+"--"+(++count));
                String str = null;
                // 制造空指针NPE
                System.out.println(str.length());
            }catch (Throwable e){
                e.printStackTrace();
            }
        }
    }

    public class FastThrowMain {
        public static void main(String[] args) throws InterruptedException {
            WithNPE withNPE = new WithNPE();
            ExecutorService executorService = Executors.newFixedThreadPool(20);
            for (int i=0; i<Integer.MAX_VALUE; i++) {
                executorService.execute(withNPE);
                // 稍微sleep一下, 是为了不要让异常抛出太快, 导致控制台输出太快, 把有异常栈信息冲掉, 只留下fast throw方式抛出的异常
                Thread.sleep(2);
            }
        }
    }

运行部分日志如下:

  WithNPE--6686
    ... ...
    java.lang.NullPointerException
        at com.afei.juc.WithNPE.run(FastThrowMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    java.lang.NullPointerException
        at com.afei.juc.WithNPE.run(FastThrowMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    java.lang.NullPointerException
        at com.afei.juc.WithNPE.run(FastThrowMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    WithNPE--6687
    WithNPE--6688
    WithNPE--6689
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    WithNPE--6690
    WithNPE--6691
    WithNPE--6692
    java.lang.NullPointerException
    java.lang.NullPointerException
    java.lang.NullPointerException
    ... ...

从这段日志可知,抛出了几千次带有详细异常栈信息的异常后,只会抛出java.lang.NullPointerException这种没有详细异常栈信息只有异常类型的异常信息。这就是Fast Throw优化后抛出的异常。如果我们配置了-XX:-OmitStackTraceInFastThrow,再次运行,就不会看到Fast Throw优化后抛出的异常,全是包含了详细异常栈的异常信息。

配置JVM参数关闭Fast Throw后,即使抛出了2w+次异常,依然全是包含了详细异常栈的异常信息,日志如下:

  WithNPE--20719
    WithNPE--20720
    java.lang.NullPointerException
        at com.afei.juc.WithNPE.run(FastThrowMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
    java.lang.NullPointerException
        at com.afei.juc.WithNPE.run(FastThrowMain.java:21)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

作者:阿飞的博客

来源:https://www.jianshu.com/p/cc1bd35466cb


JS中文网,Javascriptc中文网是中国领先的新一代开发者社区和专业的技术媒体,一个帮助开发者成长的社区,是给开发者用的 Hacker News,技术文章由为你筛选出最优质的干货,其中包括:Android、iOS、前端、后端等方面的内容。目前已经覆盖和服务了超过 300 万开发者,你每天都可以在这里找到技术世界的头条内容。

本文著作权归作者所有,如若转载,请注明出处

转载请注明:文章转载自「 Java极客技术学习 」https://www.javajike.com

标题:异常栈信息不见了之JVM参数OmitStackTraceInFastThrow

链接:https://www.javajike.com/article/1768.html

« 东半球第二详细JVM内存占用情况深入分析
FullGC实战:业务小姐姐查看图片时一直在转圈圈»

相关推荐

QR code