1. 程式人生 > >Java執行時故障排查

Java執行時故障排查

最近單獨負責一個應用上線,由於經驗不足,踩了很多坑,記錄一下,方便以後檢視。

剛開始我的try,catch是這樣寫的:

try {
    mediaType = detector.detect(inputStream, metadata);
    parser.parse(inputStream, handler, metadata, parseContext);
} catch (TikaException e) {
    handleTikaExcetion(e);
} catch (SAXException e) {
    throw new BadRequestException("檔案不符合SAX標準"
); } catch (IOException e) { return handleIOException(e); } catch (RuntimeException e) { throw new BadRequestException(e.getMessage()); }

結果發現應用跑著跑著就掛了,而且還沒有報警…
一臉蒙逼,其實我不介意你掛,最起碼你得給我個報警什麼的吧…

跑到伺服器上,去查了一下日誌,果真什麼都沒有… 好吧,重現了一遍故障,發現瞭如下內容:

java.lang.OutOfMemoryError: Java heap space
at java.util
.Arrays.copyOf(Arrays.java:2367) ~[na:1.8.0_45] at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130) ~[na:1.8.0_45] at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114) ~[na:1.8.0_45] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java
:415) ~[na:1.8.0_45] at java.lang.StringBuilder.append(StringBuilder.java:132) ~[na:1.8.0_45]

虛擬機器崩了,然而我並沒有捕獲Error,於是它就悄無聲息的離開了我…

於是修改了程式碼,就像這樣子(注意不要被我帶壞,這個地方對業務來說忽略時合理的):

try {
    mediaType = detector.detect(inputStream, metadata);
    parser.parse(inputStream, handler, metadata, parseContext);
} catch (TikaException e) {
    handleTikaExcetion(e);
} catch (SAXException e) {
    throw new BadRequestException("檔案不符合SAX標準");
} catch (IOException e) {
    return handleIOException(e);
} catch (RuntimeException e) {
    throw new BadRequestException(e.getMessage());
} catch (Throwable ignored) {
}

過了不多久,發現虛擬機器又沒響應了,對,是又。

不過這次很奇怪,虛擬機器沒掛,只是好像阻塞住了,莫非是死鎖?
於是用jstack -pid查看了一下它究竟在做什麼,竟然發現它真的在阻塞。
就像這樣:

"com.package.FullIndex.main()" #30 prio=5 os_prio=31 tid=0x00007f89ca2e7000 nid=0x6713 runnable in Object.wait() [0x0000000107c68000]
    at com.package.FullIndex.main(FullIndex.java:22)
"main" #1 prio=5 os_prio=31 tid=0x00007f89c2029000 nid=0x1303 in Object.wait() [0x0000000107c68000]
    at org.apache.maven.cli.MavenCli.main(MavenCli.java:141)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:409)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:352)
    at org.codehaus.classworlds.Launcher.main(Launcher.java:47)

追著呼叫棧,找到了阻塞的原因:被傳入了一個沒有設定讀取超時時間的來自網路的InputStream。
於是換另一個介面,自己用socket拿InputStream,終於,世界清靜了。

但是我還是too yong,too simple。不一會程式又因為OOM掛了,只不過這次OOM又換了一個地方…。我這個業務只是過來索引富文字文件,3G記憶體還不夠用?

找到了掛掉的對應記錄,看起來是這樣的:
path=’/bio/soapsnp/kasalath_genome/all.fasta/’,size=409164635
400M的檔案,吞進記憶體夠存7份了,為什麼不夠用?還有這個字尾是什麼鬼…
去Google了一下,這份檔案是人類基因組描述人類基因的檔案…
人類就能隨便欺負程式猿嗎?為什麼讀到記憶體就OOM?

於是,用jmap和jhat看了一眼虛擬機器的記憶體,居然有一個2.6G的char陣列。
原來 ISO-8859-1編碼轉成unicode編碼之後,大了那麼多…
最後在迴圈的地方又加了一遍try-catch,用來規避提取內容之外的OOM,並且加入了截斷的功能。
加完後看起來是這樣的:

try {
    msgHandleService.singleAction(msgModel, SyncEnum.create);
} catch (BadRequestException ignored) {
} catch (RetryException e) {
    indexStorage(storageTree, retryTime + 1);
    return;
} catch (Throwable error) { // ignore it and retry later
    LOG.error(msgModel.toString(), error);
}

終於,世界都清淨了~