Too Many Open files

最近发现了一个历史 bug,挺有意思,记录一下。

环境:JDK7
系统:CentOS
现象:长时间运行后程序无响应

开始我怀疑是不是哪里死锁了,找了一圈也没有发现问题;
后来再次出现该问题时尝试使用 jstack 查看当前状态,然而出现以下信息:

1
2
Unable to open socket file: target process not responding or HotSpot VM not loaded
The -F option can be used when the target process is not responding

再次加上 -F 参数:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
java.lang.RuntimeException: Unable to deduce type of thread from address 0x00007fb1f430f000 (expected type JavaThread, CompilerThread, ServiceThread, JvmtiAgentThread, or SurrogateLockerThread)
at sun.jvm.hotspot.runtime.Threads.createJavaThreadWrapper(Threads.java:166)
at sun.jvm.hotspot.runtime.Threads.first(Threads.java:150)
at sun.jvm.hotspot.runtime.DeadlockDetector.createThreadTable(DeadlockDetector.java:149)
at sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:56)
at sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:39)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:62)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:45)
at sun.jvm.hotspot.tools.JStack.run(JStack.java:66)
at sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:260)
at sun.jvm.hotspot.tools.Tool.start(Tool.java:223)
at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118)
at sun.jvm.hotspot.tools.JStack.main(JStack.java:92)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.tools.jstack.JStack.runJStackTool(JStack.java:140)
at sun.tools.jstack.JStack.main(JStack.java:106)
...

完全无法查看到任何有用的信息。
开始怀疑是不是有内存泄露,然而 JAVA 是存在自动回收机制的,这要排查哪里的问题似乎不太容易。
后来在 LOG 输出中发现了一条错误:Too Many Open files error,很多打开文件操作都出现了这个错误,那就是有文件没有正确关闭了?

一般运行的程序都有一个 Max open files 的最大限制1

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
$ cat /proc/PID/limits
Limit Soft Limit Hard Limit Units
Max cpu time unlimited unlimited seconds
Max file size unlimited unlimited bytes
Max data size unlimited unlimited bytes
Max stack size 8388608 unlimited bytes
Max core file size 0 unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 63177 63177 processes
Max open files 8192 1048576 files
Max locked memory 16777216 16777216 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 63177 63177 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Max realtime timeout unlimited unlimited us

当超出当前限制,程序将无法申请打开任何新的句柄。那么如何查看当前已经使用了多少资源呢?

1
$ ls -la /proc/PID/fd

不看不知道一看吓一跳,原来程序中有很多 socket 连接,后来发现其中网络部分有连接使用完没有正确 close,就是这样一个小疏忽,最终造成程序死机。

最后一个没有用到的,我现在怀疑 jstack 报错可能和这个也有关系,如果临时调整 Max open files 参数是不是可以解决这个报错呢?
查找到可以使用以下命令动态调整进程限制文件数量:

1
prlimit -nNUM -p PID

总结:程序稳定性测试时候也应该多多使用 jstack & limits,查看一下长时间运行后有没有不停增加的线程及文件,因为这种问题不是那么容易暴露的。


Too Many Open files
https://wishlily.github.io/article/fixbug/2020/04/19/java_ulimit/
作者
Wishlily
发布于
2020年4月19日
许可协议