1、背景

在生產(chǎn)環(huán)境中，開發(fā)人員多少都在生產(chǎn)環(huán)境中遇到過NPE異常明明printStackTrace 了，堆棧信息只有令人絕望的的”null“ 4個(gè)字母。但其實(shí)往前翻一番日志，還是會(huì)找到包含具體NPE 位置的堆棧信息，但是為什么有時(shí)候有NPE位置信息，有時(shí)候沒有呢？

又有沒有解決的必要性呢？

2、原因、方案

簡(jiǎn)書：http://www.itdecent.cn/p/03d41fb71987

Stack Overflow：https://stackoverflow.com/questions/2411487/nullpointerexception-in-java-with-no-stacktrace

We have seen this same behavior in the past.It turned out that, for some crazy reason,if a NullPointerException occurred at the same place in the code multiple times, after a while using Log.error(String, Throwable) would stop including full stack traces.

Try looking further back in your log. You may find the culprit.

2.1、原因

jvm針對(duì)頻繁出現(xiàn)的異常做了優(yōu)化,可以在出現(xiàn)異常的時(shí)候快速拋出,不需要打印出整個(gè)調(diào)用鏈,這樣可以節(jié)省異常堆棧的內(nèi)存分配。

2.2、解決方案

既然jvm針對(duì)這個(gè)做了優(yōu)化,那肯定有禁用這個(gè)優(yōu)化的方法,那就是-XX:-OmitStackTraceInFastThrow參數(shù)(禁用快拋,即展示完整異常)

3、多少次異常后不打印具體異常信息？

3.1、異常類

public class WithNPE extends Thread {

    private int count;

    public WithNPE(Integer count) {
        this.count = count;
    }

    @Override
    public void run() {
        try {
            String str = null;
            // 制造空指針NPE
            System.out.println(str.length());
        } catch (Throwable e) {
            if (e.getStackTrace().length == 0) {
                FastThrowMain.countDown();
                System.out.println();
                System.out.println();
                System.out.printf("count:" + count);
            }
        }
    }
}

3.2、測(cè)試主類

public class FastThrowMain {
    private static volatile AtomicInteger count = new AtomicInteger(0);
    private static CountDownLatch countDownLatch = new CountDownLatch(1);

    public static void main(String[] args) throws InterruptedException {
        ExecutorService executorService = Executors.newFixedThreadPool(1);
        for (int i = 0; i < 8000; i++) {
            WithNPE withNPE = new WithNPE(count.getAndIncrement());
            executorService.execute(withNPE);
        }
        countDownLatch.await();
        executorService.shutdown();
    }

    public static void countDown() {
        countDownLatch.countDown();
    }
}

3.2、運(yùn)行5次結(jié)果

count:6865
count:6913
count:6862
count:6889
count:6885

3.3、結(jié)論

jvm優(yōu)化，不打印異常堆棧信息的次數(shù)是多少呢？

筆者環(huán)境：jdk1.8.0_77
測(cè)試結(jié)果為6800-7000 之間

對(duì)于線上環(huán)境，這個(gè)數(shù)值還是挺容易達(dá)到的。

4、處理建議

雖然使用-XX:-OmitStackTraceInFastThrow 可以禁用jvm 優(yōu)化，每次異常都會(huì)打印完整堆棧信息，方便直接定位異常位置。但是筆者還是建議保持這個(gè)優(yōu)化，因?yàn)榇蛴《褩Ｐ畔⑿枰闅v整個(gè)線程堆棧，是比較耗費(fèi)性能的。

當(dāng)線上發(fā)現(xiàn)NPE沒有具體異常信息時(shí)可以嘗試向前找找日志。