來源：norwind?
我們的一個程序，假設名字為“Photo Pull”，主要解決以下問題：
從各種第三方來源上獲取聯系人照片
將照片重新調整至所需的縮略圖大小
將結果發(fā)送到S3
看起來似乎這個程序能夠理所當然的穩(wěn)定運行.但事實剛好與之相反，這是我們最容易出問題的程序之一——不是因為代碼有問題，而是Java運行時會導致問題。
漂亮的代碼, 糟糕的行為
我們遇到的第一個問題是Photo Pull運行后內存占用量持續(xù)增大。幾個小時后，這個進程將消耗掉系統的所有內存，直到被Linux OOM-killer殺掉或被Storm重啟。
常用的Java內存使用診斷工具起不了什么作用。所有我們了解到的是，非堆內存存在大量泄露，而堆內存保持在幾百MB。
然而，有一個統計學的方法來確定內存泄露的原因。導致內存泄露的組件也會使內存占用量超過任意一個閾值。如果我們在堆棧中多次跟蹤anOutOfMemoryError 錯誤，我們就有很大可能確定內存泄露的原因?，F在唯一的問題是，這個進程不能自己發(fā)現內存被耗盡，只有被Linux殺死時才知道。
這個問題的解決方法是使用ulimit命令來為該程序設置一個內存使用上限，這個上限值要顯著低于系統內存，例如:
ulimit -m $((1024*1024))
該命令是在FreeBSD系統上將程序使用內存限制為1G以內。內存使用上限設置完成后，讓程序運行一段時間，直到崩潰。
通過堆棧跟蹤，我們發(fā)現一個本地棧幀:
com.sun.imageio.plugins.jpeg.JPEGImageReader.initJPEGImageReader()
該函數是在jdk/src/share/native/sun/awt/image/jpeg/imageioJPEG.c文件中，屬于OpenJDK 6源代碼。簡單查看一下，發(fā)現如下問題:
/* ... snip to line 1450 */
/* We use our private extension JPEG error handler.
*/
jerr = malloc (sizeof(struct sun_jpeg_error_mgr));
/* ... snip to line 1476 */
/* Establish the setjmp return context for sun_jpeg_error_exit to use. */
if (setjmp(jerr->setjmp_buffer)) {
/* If we get here, the JPEG code has signaled an error. */
char buffer[JMSG_LENGTH_MAX];
(*cinfo->err->format_message) ((struct jpeg_common_struct *) cinfo,
buffer);
JNU_ThrowByName(env, "javax/imageio/IIOException", buffer);
return 0;
}
在1452行C代碼給一個錯誤的handler分配了空間，但之后一直沒有釋放，導致拋出IIOException異常.目前還不清楚cinfo是否也存在泄露。
檢查OpenJDK 7中的同一個文件，發(fā)現bug只存在于OpenJDK 6中。將代碼移植到Java 7中，運行了幾個小時后沒有發(fā)現內存泄露。
分段查找錯誤
在發(fā)現內存泄漏原因幾個小時后，程序的一個組件崩潰了，過了一會兒另外一個也崩潰了。Storm盡職盡責地重新啟動它們，但是沒有找到組件為什么被殺死的信息——沒有日志記錄，沒有內存增長，也沒有跡象表明是被Storm殺死。我們重新在本地運行程序，最終獲得如下信息:
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x00007fb120713242, pid=11629, tid=140394149959424
#
# JRE version: 7.0_25-b15
# Java VM: Java HotSpot(TM) 64-Bit Server VM (23.25-b01 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C [libpthread.so.0+0xe242] sem_post+0x12
由此產生的hs_err_pid*.log文件缺乏Java堆棧跟蹤，而由JVM產生的堆棧轉儲只包含最底層的框架。盡管如此，我們開始查找引起POSIX線程庫觸發(fā)段錯誤的條件.向sem_post傳遞18字節(jié)的信號量，得到如下內容：
e230: mov ? ?eax,DWORD PTR [rdi]
e232: cmp ? ?eax,0x7fffffff
e237: je ? ? e26c
e239: lea ? ?esi,[rax+0x1]
e23c: lock cmpxchg DWORD PTR [rdi],esi
e240: jne ? ?e232
e242: cmp ? ?QWORD PTR [rdi+0x8],0x0 ? ? ? ?# Here
e247: je ? ? e262
e249: mov ? ?eax,0xca
e24e: mov ? ?esi,0x1
e253: or ? ? esi,DWORD PTR [rdi+0x4]
e256: mov ? ?edx,0x1
e25b: syscall
e25d: test ? rax,rax
e260: js ? ? e265
e262: xor ? ?eax,eax
e264: ret
e265: mov ? ?eax,0x16
e26a: jmp ? ?e271
e26c: mov ? ?eax,0x4b
e271: mov ? ?rdx,QWORD PTR [rip+0x209d08]
e278: mov ? ?DWORD PTR fs:[rdx],eax
e27b: or ? ? eax,0xffffffff
e27e: ret
這一失敗本身，是相當令人吃驚的.只有早期在e230處有幾個指令訪問rdi寄存器成功，即使只有8個字節(jié)數據在內存中。但JVM將rdi寄存器放置在0x00007fb11046e000。 添加八個字節(jié)不可能跨越頁邊界。 幸運的是，JVM轉儲也給了我們一個內存映射。事實證明，這個內存地址指向到一個本地共享庫：
7fb11046d000-7fb11046e000 rw-p 00007000 ca:01 77 /lib/x86_64-linux-gnu/libnss_dns-2.15.so
7fb11046f000-7fb110473000 r--s 0008a000 ca:01 396307 /opt/jdk1.7.0/jre/lib/jsse.jar
rdi指向內存映射中有缺陷一頁的起始位置。這表明在e230執(zhí)行時存在的一些內容在e242執(zhí)行時被釋放。
但也有可能是調用者不打算使用這個地址，我們注意到rdi恰好是當前堆棧幀之上大約2^32個字節(jié)處。但是，我們仍然不知道問題出在哪里。
在重現程序崩潰10次后，我們得到了一個稍微不同的情況。再一次，我們得到一個指向POSIX線程函數的垃圾指針。 但是這一次，我們也從轉儲中得到了一個Java堆棧跟蹤。
事實證明，JRE的代碼只是委托給libccm，就像用一個嬰兒車去當成汽車使用。它會破壞POSIX線程，或者導致JVM持續(xù)的占用內存。
我們如何處理
最終的解決方案遠沒有查找問題原因本身讓人感到興奮。我們發(fā)現使用Apache Commons Imaging圖像處理類庫代替Java ImageIO庫就可以解決問題。 但是，一般來說，解決一個復雜的問題的時候，分析問題往往比修復問題花費更多的時間和精力。
