漂亮的代码，糟糕的行为——解决Java运行时的内存问题

我们的一个程序，假设名字为“Photo Pull”，主要解决以下问题：

• 从各种第三方来源上获取联系人照片
• 将照片重新调整至所需的缩略图大小
• 将结果发送到S3

看起来似乎这个程序能够理所当然的稳定运行.但事实刚好与之相反，这是我们最容易出问题的程序之一——不是因为代码有问题，而是Java运行时会导致问题。

漂亮的代码, 糟糕的行为

我们遇到的第一个问题是Photo Pull运行后内存占用量持续增大。几个小时后，这个进程将消耗掉系统的所有内存，直到被Linux OOM-killer杀掉或被Storm重启。

常用的Java内存使用诊断工具起不了什么作用。所有我们了解到的是，非堆内存存在大量泄露，而堆内存保持在几百MB。

然而，有一个统计学的方法来确定内存泄露的原因。导致内存泄露的组件也会使内存占用量超过任意一个阈值。如果我们在堆栈中多次跟踪anOutOfMemoryError 错误，我们就有很大可能确定内存泄露的原因。现在唯一的问题是，这个进程不能自己发现内存被耗尽，只有被Linux杀死时才知道。

这个问题的解决方法是使用ulimit命令来为该程序设置一个内存使用上限，这个上限值要显著低于系统内存，例如:

1	ulimit -m $((1024*1024))

该命令是在FreeBSD系统上将程序使用内存限制为1G以内。内存使用上限设置完成后，让程序运行一段时间，直到崩溃。

通过堆栈跟踪，我们发现一个本地栈帧:

1	com.sun.imageio.plugins.jpeg.JPEGImageReader.initJPEGImageReader()

该函数是在jdk/src/share/native/sun/awt/image/jpeg/imageioJPEG.c文件中，属于OpenJDK 6源代码。简单查看一下，发现如下问题:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16

/* ... 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杀死。我们重新在本地运行程序，最终获得如下信息:

1 2 3 4 5 6 7 8

# 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字节的信号量，得到如下内容：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24

e230: mov    eax, DWORD PTR [rdi] e232: cmp    eax,0x7fffffff e237: je     e26c <sem_post+0x3c> e239: lea    esi,[rax+0x1] e23c: lock cmpxchg DWORD PTR [rdi],esi e240: jne    e232 <sem_post+0x2> e242: cmp    QWORD PTR [rdi+0x8],0x0        # Here e247: je     e262 <sem_post+0x32> 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 <sem_post+0x35> e262: xor    eax,eax e264: ret e265: mov    eax,0x16 e26a: jmp    e271 <sem_post+0x41> 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转储也给了我们一个内存映射。事实证明，这个内存地址指向到一个本地共享库：

1 2	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库就可以解决问题。 但是，一般来说，解决一个复杂的问题的时候，分析问题往往比修复问题花费更多的时间和精力。

原文链接： fullcontact 翻译： ImportNew.com - norwind
译文链接： http://www.importnew.com/10163.html
[ 转载请保留原文出处、译者和译文链接。]

2

相关文章

• 记录异常日志的7条规则
• Android 4.2原生支持从右到左的文字排列格式
• Android vs iOS 游戏之迷思
• 免费在线阅读“Gradle Beyond the Basics”
• Android手机分布图，市场很挤涌
• clone方法是如何工作的
• 100个高质量Java开发者博客
• Netty教程—Part1—介绍
• Arrays.sort()你应该知道的事
• Java8中的java.util.Random类