一個ScheduledExecutorService啓動的Java線程無端掛掉引起的思考

2018年12月12日18:44:53

一個ScheduledExecutorService啓動的Java線程無端掛掉引起的思考

案件現場

不久前，在開發改造公司一個端到端監控日誌系統的時候，出現了一個bug：有個掃表寫日誌的線程無端掛掉。

順藤摸瓜

我看了好久的代碼，都沒有想出來有什麼地方有邏輯問題。萬金油的方法是，重啓。當我滿心歡喜地認爲重啓是個好方法的時候，問題又重現了。

我有點無奈地看着本身的代碼

本我：堪稱完美的邏輯，還有什麼地方是我沒有注意到的嗎？

真我：固然有了，你這個菜鳥，你不知道的地方多着呢。

因而，去找老大問一下問題怎麼解決，老大說去生產數據庫上導十萬數據到測試庫，而後在本地debug一下。接着，我就從數據庫裏面導出一萬數據開始測試，在eclipse啓動進程，日誌寫在本地文件。很快，問題再一次出現。而後斷點，而後找到出問題的地方。出問題的地方以下：

代碼就一行：

String timeStamp = DateUtil.str2Date(receiveTime, DateUtil.YYYYMMDDHH24MISS).getTime() + "000";

這行代碼的意思是，將字符串的接收時間receiveTime格式化，getTime()獲得時間戳，由於格式是要微秒，加了三個零。

DateUtil.str2Date方法：（String時間轉化爲Date類型，關於時間轉換能夠看看本人的String、Date和Timestamp的互轉）

public static Date str2Date(String dateStr, String dateFormat){
    if (StringHelper.isEmpty(dateStr)) {
        return null;
    }

    SimpleDateFormat df = new SimpleDateFormat(dateFormat);
    try {
        return df.parse(dateStr);
    } catch (Exception ex) {
        return null;
    }
}

這個工具類當parse方法拋出異常的時候返回null，看起來是沒有問題的，可是我在轉換以後沒有判斷是否爲空即null，而後就變成了null.getTime()，接着就拋了一個很常見的NullPointerException異常。

到這裏，看似問題已經解決了，可是問題並無那麼簡單。

尋根問底

上面說到的在線程中拋出了NullPointerException異常，解決方法是增長一個判斷是否爲空的條件就能夠了。可是通常來講，有異常的時候，程序沒有捕獲異常，日誌裏或者debug時控制檯會打印異常信息，相似這種：

at com.netease.backend.rds.task.CleanHandleThread.run(CleanHandleThread.java:65)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)

但實際上我debug的時候，並無看到打印的異常信息。我是斷點到這一步，發現下一行代碼沒有執行，我就判定問題是在這裏，並且空指針異常一會兒就能看出來了。問題來了，爲何沒有打印異常信息呢？我想應該是線程的問題，代碼裏啓動這個寫日誌的定時任務用的是ScheduledExecutorService：

我Google了一下，發現其實有不少前輩都曾遇到過這個問題。

在這些文章中，我找到了我要的答案。我引用其中的一篇文章從一個java線程掛掉的例子討論分析定位問題基本原則文字做爲答案吧。

那麼，Java線程掛掉的主要緣由是：Any thrown exception or error reaching the executor causes the executor(ScheduledExecutorService) to halt. No more invocations on the Runnable, no more work done. This work stoppage happens silently, you’ll not be informed.

也就是說，若是使用者拋出異常，ScheduledExecutorService 將會中止線程的運行，並且不會報錯，沒有任何提示信息。

這就是在日誌中和控制檯都沒有看到打印異常信息的緣由。

解決方法

寫了一個測試類，有興趣能夠研究一下這個bug。

public class ScheduledExecutorServiceThrowExceptionTest {
    
    private static int i = 0;
    
    public static void main(String[] args) {
        ScheduledExecutorService exc = Executors.newSingleThreadScheduledExecutor();
        exc.scheduleAtFixedRate(new Runnable(){

            @Override
            public void run() {
                i++;
                if (i==6) {
                    throw new RuntimeException();
                } else {
                    System.out.println(i);
                }
                
            }
            
        }, 0, 1, TimeUnit.SECONDS);
            
    }

}

測試結果是：

結果顯示，當程序拋出異常的時候，線程就再也不運行了，也就是掛了。

解決方法：

• 一、直接加一個try-catch進行異常捕獲，而後你能夠打印你須要的異常信息或者處理異常。

public class ScheduledExecutorServiceThrowExceptionTest1 {
    
    private static int i = 0;
    
    public static void main(String[] args) {
        ScheduledExecutorService exc = Executors.newSingleThreadScheduledExecutor();
        exc.scheduleAtFixedRate(new Runnable(){

            @Override
            public void run() {
                try {
                    // doSomething();// TODO：具體業務邏輯
                    i++;
                    if (i==6) {
                        throw new RuntimeException();
                    } else {
                        System.out.print(i + " ");
                    }
                } catch (Exception ex) {
                    System.out.println();
                    System.out.println("在ScheduledExecutorService中有異常拋出，異常堆棧：" + ex.getStackTrace());
                }
            }
            
        }, 0, 1, TimeUnit.SECONDS);
            
    }

}

結果是打印了異常信息，且線程沒有被中斷。

1 2 3 4 5 
在ScheduledExecutorService中有異常拋出，異常堆棧：[Ljava.lang.StackTraceElement;@1bb53ed8
7 8 9 10 11 12 13

• 二、經過ScheduledFuture對象返回異常信息

public class ScheduledExecutorServiceThrowExceptionTest2 {

    private static int i = 0;
    
    public static void main(String[] args) {
        ScheduledExecutorService exc = Executors.newSingleThreadScheduledExecutor();
        ScheduledFuture<?> handle = exc.scheduleAtFixedRate(new Runnable(){

            @Override
            public void run() {
                i++;
                if (i==6) {
                    throw new RuntimeException();
                } else {
                    System.out.print(i + " ");
                }
                
            }
            
        }, 0, 1, TimeUnit.SECONDS);
        
        try {
            handle.get();
        } catch(Exception ex) {
            System.out.println();
            System.out.println("在ScheduledExecutorService中有異常拋出，異常堆棧：" + ex.getStackTrace());
        }
            
    }

}

這個解決方法打印了異常信息，可是並無阻止線程掛掉。

1 2 3 4 5 
在ScheduledExecutorService中有異常拋出，異常堆棧：[Ljava.lang.StackTraceElement;@33909752

總結

一個ScheduledExecutorService啓動的Java線程無端掛掉的緣由是：若是使用者拋出異常，ScheduledExecutorService 將會中止線程的運行，並且不會報錯，沒有任何提示信息。解決方法是：try-catch將異常信息打印，或者用ScheduledFuture<?>獲取線程運行結果。

寫的bug多，天然經驗就多了，可是要注意總結。

完

2018年12月13日09:08:19