诊断 mimepull.jar 导致的大量临时文件不能释放的问题

某天某个应用程序的某些服务器突然大量抛出下面异常:

msg=Error executing HystrixCommand 'xxxClient', failureType = COMMAND_EXCEPTION, rootcause=SocketException: Too many open files&st=com.sun.jersey.api.client.ClientHandlerException: java.net.SocketException: Too many open files

很明显, 这个应用打开了太多的文件句柄, 没有关闭. 为了缓解问题, 重启服务器临时解决. 到底哪里出了问题呢? 为什么最近才开始有这种错误? 我们一步步找出事故的原因.

首先, 我们查看了这个服务器的 open file 的限制:
```
$ ulimit -n
65535
```
看上去这是默认的值, 平时我们也不可能打开这么多. 所以这个没人调整过.
查看该 Java 进程打开的文件句柄数:
```
$ pgrep java
302491
$ ls /proc/302491/fd/ | wc -l
55517
```
可以看到, 这个 Java 进程确实打开了非常多的文件, 我们知道在 Linux 的世界里, 很多都是以文件的形式存在, 有可能是网络 IO, 也有可能是 IPC 之类的, 那么到底是什么文件打开这么多, 有么有什么模式呢?

查看文件模式. 对这些打开的文件名进行观察, 发现绝大多数都是这个模式:

$ ls -lh /proc/302491/fd/
lrwx------ 1 appuser app 64 Oct 28 07:49 16274 -> 
/opt/app/Tomcat/temp/MIME1940124091207464001.tmp

如果我们查看这种文件的数量, 可以看到绝对数量很大:

$ ls -lsh  /proc/302491/fd/ | grep MIME | wc -l
54863

那么是哪里打开了这么多文件呢? 我们使用 btrace 查看文件的创建:

import static org.openjdk.btrace.core.BTraceUtils.jstackStr;
import static org.openjdk.btrace.core.BTraceUtils.println;

import org.openjdk.btrace.core.BTraceUtils.Strings;
import org.openjdk.btrace.core.annotations.BTrace;
import org.openjdk.btrace.core.annotations.OnMethod;
import org.openjdk.btrace.core.annotations.ProbeClassName;
import org.openjdk.btrace.core.annotations.ProbeMethodName;

@BTrace 
public class NewFileTracer {

 @OnMethod( clazz="/java\\.io\\.File/", method="<init>" )
 public static void createException(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, String fileName) {
   if (Strings.startsWith(fileName, "MIME")) {
       println(Strings.strcat("trace ... entered ", probeClass));
       println(jstackStr());
   }
 }
}

在运行的机器上注入之后, 发现了打开文件的栈:

trace ... entered java.io.File
java.io.File.<init>(File.java:275)
java.io.File$TempDirectory.generateFile(File.java:1890)
java.io.File.createTempFile(File.java:1987)
java.io.File.createTempFile(File.java:2047)
org.jvnet.mimepull.MemoryData.createNext(MemoryData.java:87)
org.jvnet.mimepull.Chunk.createNext(Chunk.java:59)
org.jvnet.mimepull.DataHead.addBody(DataHead.java:82)
org.jvnet.mimepull.MIMEPart.addBody(MIMEPart.java:192)
org.jvnet.mimepull.MIMEMessage.makeProgress(MIMEMessage.java:235)
org.jvnet.mimepull.MIMEMessage.parseAll(MIMEMessage.java:176)
org.jvnet.mimepull.MIMEMessage.getAttachments(MIMEMessage.java:101)     
com.sun.jersey.multipart.impl.MultiPartReaderClientSide.readMultiPart(MultiPartReaderClientSide.java:177)
com.sun.jersey.multipart.impl.MultiPartReaderClientSide.readFrom(MultiPartReaderClientSide.java:139)
com.sun.jersey.multipart.impl.MultiPartReaderClientSide.readFrom(MultiPartReaderClientSide.java:77)
com.sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:553)
com.sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:506)
com.sun.jersey.api.client.WebResource.handle(WebResource.java:674)
com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
com.sun.jersey.api.client.WebResource$Builder.post(WebResource.java:553)
... 省略业务相关代码
java.util.concurrent.FutureTask.run(FutureTask.java:262)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
java.lang.Thread.run(Thread.java:748)

根据上面的出错栈, 我们找到了打开文件的代码, 它是 jersey-multipart-1.8.jar 引入的 mimepull-1.4.jar 出的问题. 可以看到在源代码: https://github.com/javaee/metro-mimepull/blob/mimepull-1.4/src/main/java/org/jvnet/mimepull/WeakDataFile.java#L93 这里有个 close() 方法, 可能某些代码没有 close().

进一步审查 mimepull 1.4 版本的代码, 发现如果jersey 收到的 response 是 multipart/mixed 这种 content-type, 并且附件有多个, 并且设置不是 onlyMemory, 那么就有可能触发这个 bug, 导致打开的文件句柄越来越多.
https://github.com/javaee/metro-mimepull/blob/mimepull-1.4/src/main/java/org/jvnet/mimepull/MemoryData.java#L82~L91

 public Data createNext(DataHead dataHead, ByteBuffer buf) {
   if (!config.isOnlyMemory() && dataHead.inMemory >= config.memoryThreshold) {
       try {
           String prefix = config.getTempFilePrefix();
           String suffix = config.getTempFileSuffix();
           File dir = config.getTempDir();
           File tempFile = (dir == null)
                   ? File.createTempFile(prefix, suffix)
                   : File.createTempFile(prefix, suffix, dir);
           LOGGER.fine("Created temp file = "+tempFile);
           dataHead.dataFile = new DataFile(tempFile); //直接替换, 未关

这个问题最终在 1.8 版本修复: https://github.com/eclipse-ee4j/metro-mimepull/issues/2. 可是这个修复中使用了 File.deleteOnExit() 方法, 有人还是抱怨这个可能引起内存泄漏, 细心的读者可以再看看这个 issue: https://github.com/javaee/metro-mimepull/issues/13

添加新评论