一帆磨砺

生活所迫,一叶孤舟

0%

记一次文件句柄大量占用(泄露)排查

写在开头

  1. 本次场景发生于测试场景(万幸),触发原因为服务不可用,后台日志出现大量

    1
    java.io.IOException: Too many open files

    ,基本连接mysql/redis等等相关代码都会抛出此异常,因此面向搜索引擎得出结论,该进程文件句柄数已达到该进程的上限。

  2. 本文采取的测试方法基本都会对机器以及应用造成影响,因此请尽量不要在线上环境采取相同操作,以免产生不可预期的经济损失

问题初发

​ 由于测试环境经常重启,因此之前一直未能触发该异常,本次因特殊原因,应用存活了4-5天还未被重启,并且服务不可用毫无征兆,突然所有后端接口都抛出异常,查看日志发现大量的java.io.IOException: Too many open files,并且mysql/redis等等均连接异常。

​ 一开始睿智的以为是File对象创建过多导致(事实上File类基本没有资源泄露问题),第一次修改后重启,发现应用正常,喜滋滋的以为解决问题。24 hours later,总感觉不太对,于是使用命令lsof -n -p {pid}|wc -l查看应用文件句柄数,发现文件句柄激增至20k,并且由于lsof -n -p {pid} > fileLead.log导出的数据无法定位具体文件句柄泄露的原因以及位置,遂使用jmap -dump将heap的信息先保存,并使用工具mat进行分析,通过Leak Suspects的分析,可以看出,,在查看具体对象后,发现是MQ相关对象过多,成为最大嫌疑,于是乎开始排查应用中关于MQ的使用,尤其是producer.shutdown();,查看源码后发现,每次成功shutdown都会打印the producer [{}] shutdown OK,于是在路径/home/{用户}/logs/rocketmqlogs/otherdays查看MQ的关闭日志,由于文件句柄大量激增,简单的认为MQ的连接未能成功关闭,通过vim的命令%s/shutdown OK//ng查出存在一定的成功关闭,成功自闭。

​ 通过多次的面相搜索引擎开发,查到一个定位文件句柄泄露的好工具file-leak-detector,由于是测试环境,使用nohup java -javaagent:path/to/file-leak-detector.jar=http=19999 -jar test.jar &重启应用,在等待几个钟头后,通过命令lsof -n -p {pid}|wc -l确认文件句柄数量已经开始大量增加,于是通过wget http://localhost:19999将文件句柄信息下载下来,通过该文件,可以很清晰的看到本次问题的罪魁祸首(定时任务ES使用未关闭连接),改之,再次部署重启。48 hours later,再次查看文件句柄数量发现稳定在120 - 150左右。至此,此次问题修改完毕,但是本次问题修改,并未成功找出出现该异常的根本原因,只能说,关于连接一类的东西,再多些谨慎为好。

欢迎关注我的其它发布渠道