漂亮的代码，糟糕的行为—解决 Java 运行时的内存问题
来源：norwind
我们的一个程序，假设名字为“Photo Pull”，主要解决以下问题：
从各种第三方来源上获取联系人照片
将照片重新调整至所需的缩略图大小
将结果发送到S3
看起来似乎这个程序能够理所当然的稳定运行.但事实刚好与之相反，这是我们最容易出问题的程序之一——不是因为代码有问题，而是Java运行时会导致问题。
漂亮的代码, 糟糕的行为
我们遇到的第一个问题是Photo Pull运行后内存占用量持续增大。几个小时后，这个进程将消耗掉系统的所有内存，直到被Linux OOM-killer杀掉或被Storm重启。
常用的Java内存使用诊断工具起不了什么作用。所有我们了解到的是，非堆内存存在大量泄露，而堆内存保持在几百MB。
然而，有一个统计学的方法来确定内存泄露的原因。导致内存泄露的组件也会使内存占用量超过任意一个阈值。如果我们在堆栈中多次跟踪anOutOfMemoryError 错误，我们就有很大可能确定内存泄露的原因。现在唯一的问题是，这个进程不能自己发现内存被耗尽，只有被Linux杀死时才知道。
这个问题的解决方法是使用ulimit命令来为该程序设置一个内存使用上限，这个上限值要显著低于系统内存，例如:
ulimit -m $((1024*1024))
该命令是在FreeBSD系统上将程序使用内存限制为1G以内。内存使用上限设置完成后，让程序运行一段时间，直到崩溃。
通过堆栈跟踪，我们发现一个本地栈帧:
com.sun.imageio.plugins.jpeg.JPEGImageReader.initJPEGImageReader()
该函数是在jdk/src/share/native/sun/awt/image/jpeg/imageioJPEG.c文件中，属于OpenJDK 6源代码。简单查看一下，发现如下问题:
/* ... 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中的同一个文件，发现bug只存在于OpenJDK 6中。将代码移植到Java 7中，运行了几个小时后没有发现内存泄露。
分段查找错误
在发现内存泄漏原因几个小时后，程序的一个组件崩溃了，过了一会儿另外一个也崩溃了。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线程库触发段错误的条件.向sem_post传递18字节的信号量，得到如下内容：
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个字节数据在内存中。但JVM将rdi寄存器放置在0x00007fb11046e000。 添加八个字节不可能跨越页边界。 幸运的是，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执行时存在的一些内容在e242执行时被释放。
但也有可能是调用者不打算使用这个地址，我们注意到rdi恰好是当前堆栈帧之上大约2^32个字节处。但是，我们仍然不知道问题出在哪里。
在重现程序崩溃10次后，我们得到了一个稍微不同的情况。再一次，我们得到一个指向POSIX线程函数的垃圾指针。 但是这一次，我们也从转储中得到了一个Java堆栈跟踪。
事实证明，JRE的代码只是委托给libccm，就像用一个婴儿车去当成汽车使用。它会破坏POSIX线程，或者导致JVM持续的占用内存。
我们如何处理
最终的解决方案远没有查找问题原因本身让人感到兴奋。我们发现使用Apache Commons Imaging图像处理类库代替Java ImageIO库就可以解决问题。 但是，一般来说，解决一个复杂的问题的时候，分析问题往往比修复问题花费更多的时间和精力。
