java.io.IOException: Too many open files

来源:互联网 发布:办公考勤软件 编辑:程序博客网 时间:2024/05/21 09:07
2014-11-01 19:43:12,997  WARN (AbstractConnector.java:472) - 
java.io.IOException: Too many open files
at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:226)
at org.eclipse.jetty.server.ServerConnector.accept(ServerConnector.java:336)
at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:467)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:607)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:536)
at java.lang.Thread.run(Thread.java:722)


Last login: Sat Nov  1 17:35:34 2014 from 220.184.86.17
[root@www ~]# free
             total       used       free     shared    buffers     cached
Mem:      16282708   16127828     154880          0       9148   13197512
-/+ buffers/cache:    2921168   13361540
Swap:      8208376          0    8208376

上周五20:22左右,服务器突然挂掉,LOG里全是“java.io.IOException: Too many open files”。
我在周六16点多重启服务器以后,第二天发现在周六19:36左右的时候,又挂掉了,现象完全一样。
挂掉时,free很少,cached很多。这次,我没有重启服务器,而是清除了一下cache,就恢复了。

从服务器的流量图中可以看到,从上周五开始,流入的流量(蓝色线)突然飚的很高。
而之前,它都是维持在很低的水平的,感觉像遭受了攻击一样。这个还要再分析了。
从年流量图上看,8月份(Aug)流入的流量也很高,这估计是因为8月中才加的防火墙:


// 查看定时日志,发现20点以前都是好的,21点以后就挂了(内存耗尽,文件句柄用光)# cat /home/lsofc.log===========================2014年 11月 07日 星期五 16:00:01 CSTMemory usage | [Use:5782 MB][Free:10118 MB][Cached:3942 MB] File count | [All count:6957][JAVA count:912] ===========================2014年 11月 07日 星期五 17:00:01 CSTMemory usage | [Use:5806 MB][Free:10094 MB][Cached:3950 MB] File count | [All count:5855][JAVA count:864] ===========================2014年 11月 07日 星期五 18:00:02 CSTMemory usage | [Use:5807 MB][Free:10093 MB][Cached:3957 MB] File count | [All count:5717][JAVA count:980] ===========================2014年 11月 07日 星期五 19:00:01 CSTMemory usage | [Use:5789 MB][Free:10110 MB][Cached:3951 MB] File count | [All count:5837][JAVA count:1106] ===========================2014年 11月 07日 星期五 20:00:01 CSTMemory usage | [Use:5830 MB][Free:10070 MB][Cached:3994 MB] File count | [All count:6115][JAVA count:1033] ===========================2014年 11月 07日 星期五 21:00:01 CSTMemory usage | [Use:14002 MB][Free:1898 MB][Cached:11084 MB] File count | [All count:70417][JAVA count:65718] ===========================2014年 11月 07日 星期五 22:00:01 CSTMemory usage | [Use:15732 MB][Free:169 MB][Cached:12875 MB] File count | [All count:70406][JAVA count:65718] ===========================2014年 11月 07日 星期五 23:00:01 CSTMemory usage | [Use:15749 MB][Free:150 MB][Cached:12847 MB] File count | [All count:70394][JAVA count:65718] // 服务器挂掉后,查看各种信息# free -m             total       used       free     shared    buffers     cachedMem:         15901      15742        158          0        127      12784-/+ buffers/cache:       2830      13070Swap:         8015          2       8013// 打开的文件数,超出了限制(65536)# lsof -n | wc -l70091// 网络相关的文件句柄数,也非常多# lsof -n -i | wc -l62548// 网络连接数,也非常多# netstat -ant | wc -l63777// 端口为54104的连接数,也非常多# netstat -ant | grep ":54104" | wc -l61101// 查看端口为54104的各种状态的连接数,发现CLOSE_WAIT的超多# netstat -ant | grep ":54104" | awk '{print $6}' | sort | uniq -c  | sort -nr   54166 CLOSE_WAIT   6920 ESTABLISHED     10 SYN_RECV      1 LISTEN// 所有网络连接数,按状态排序# netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print S[a],a}' | sort -nr 54184 CLOSE_WAIT8239 ESTABLISHED926 FIN_WAIT2207 FIN_WAIT164 TIME_WAIT46 LAST_ACK31 SYN_RECV1 CLOSING// 所有打开文件数,按进程PID排序# lsof -n | awk '{print $2}' | sort -n | uniq -c | sort -nr | more  65605 18374    741 1348    313 1349    236 1350    149 18407// 发现确实是JAVA进程搞的鬼# jps18374 DesktopServerLauncher14690 Bootstrap// 关闭的JAVA进程# ./shutdown.sh shutting downkilling pid 18374process has been shutdown// 查看一下,确实关闭了# jps14690 Bootstrap25788 Jps// 再查看打开文件数,就少了JAVA进程的了# lsof -n | awk '{print $2}' | sort -n | uniq -c | sort -nr | more    637 1348    547 1349    296 1350    126 1336    112 14690     86 25007// 重启JAVA进程# ./startup.sh starting from ./boot.sh ...     // 查看一下,确实重启了#jps25829 DesktopServerLauncher14690 Bootstrap25893 Jps// 刚启动,其打开的文件数,并不多(428)# lsof -n | awk '{print $2}' | sort -n | uniq -c | sort -nr | head -5   1056 1347   1052 1350   1040 1349   1037 1348    428 25829// 过了很久,再查看日志。发现:Cached很多,打开文件数很少,系统运行正常。// 因此,得出结论:该问题与Cached无关,只跟打开的文件数太多有关系。# tail -8 /home/lsofc.log ===========================2014年 11月 07日 星期五 23:00:01 CSTMemory usage | [Use:15749 MB][Free:150 MB][Cached:12847 MB] File count | [All count:70394][JAVA count:65718] ===========================2014年 11月 08日 星期六 00:00:01 CSTMemory usage | [Use:14498 MB][Free:1404 MB][Cached:12697 MB] File count | [All count:4272][JAVA count:232]
由此判断,并非系统广播,而是遭受攻击导致的。

0 0