文章目錄
現象描述
- 2022-08-08 11點開始好幾個業務系統相繼拋出錯誤，其中一個業務系統拋出的錯誤截圖如下：
- UidService是用作分布式id生成的服務，打開uid-service服務日志如下，看到從 2022-08-08 23:05:32 開始大量拋出“打開的文件過多”的錯誤日志。熟悉Linux的同學，對這個都不應該默認，這個一般是應為單個進程打開的 File Descriptor（簡稱：文件描述符） 太多導致的（注：Linux中一切皆文件，當進程對文件進行讀寫或是打開網絡連接時都會產生fd；OS處于安全考慮都會對fd的個數加以限制，CentOS中默認為每個進程1024個）。
2022-08-08
23:05:32.614 WARN
30239 ---
[nio-8777-exec-8
] o.s.r.s.RemoteInvocationTraceInterceptor
: Processing of HessianServiceExporter remote call resulted
in fatal exception: com.ccjt.eip.web.service.IUidService.nextProjectNoredis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the poolat redis.clients.util.Pool.getResource
(Pool.java:53
) ~
[jedis-2.9.0.jar
!/:na
]at redis.clients.jedis.JedisPool.getResource
(JedisPool.java:226
) ~
[jedis-2.9.0.jar
!/:na
]at cn.hutool.db.nosql.redis.RedisDS.getJedis
(RedisDS.java:136
) ~
[hutool-all-4.6.8.jar
!/:na
]at com.ccjt.eip.web.service.impl.UidServiceImpl.connectRedis
(UidServiceImpl.java:45
) ~
[classes
!/:0.0.1-SNAPSHOT
]at com.ccjt.eip.web.service.impl.UidServiceImpl.nextProjectNo
(UidServiceImpl.java:146
) ~
[classes
!/:0.0.1-SNAPSHOT
]at sun.reflect.GeneratedMethodAccessor57.invoke
(Unknown Source
) ~
[na:na
]at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAccessorImpl.java:43
) ~
[na:1.8.0_171
]at java.lang.reflect.Method.invoke
(Method.java:498
) ~
[na:1.8.0_171
]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection
(AopUtils.java:344
) ~
[spring-aop-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint
(ReflectiveMethodInvocation.java:198
) [spring-aop-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed
(ReflectiveMethodInvocation.java:163
) [spring-aop-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.remoting.support.RemoteInvocationTraceInterceptor.invoke
(RemoteInvocationTraceInterceptor.java:78
) ~
[spring-context-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed
(ReflectiveMethodInvocation.java:186
) [spring-aop-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke
(JdkDynamicAopProxy.java:212
) [spring-aop-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at com.sun.proxy.
$Proxy69.nextProjectNo
(Unknown Source
) [na:na
]at sun.reflect.GeneratedMethodAccessor57.invoke
(Unknown Source
) ~
[na:na
]at sun.reflect.DelegatingMethodAccessorImpl.invoke
(DelegatingMethodAccessorImpl.java:43
) ~
[na:1.8.0_171
]at java.lang.reflect.Method.invoke
(Method.java:498
) ~
[na:1.8.0_171
]at com.caucho.hessian.server.HessianSkeleton.invoke
(HessianSkeleton.java:302
) [hessian-4.0.60.jar
!/:3.1.0
]at com.caucho.hessian.server.HessianSkeleton.invoke
(HessianSkeleton.java:217
) [hessian-4.0.60.jar
!/:3.1.0
]at org.springframework.remoting.caucho.HessianExporter.doInvoke
(HessianExporter.java:228
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.remoting.caucho.HessianExporter.invoke
(HessianExporter.java:144
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.remoting.caucho.HessianServiceExporter.handleRequest
(HessianServiceExporter.java:64
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle
(HttpRequestHandlerAdapter.java:53
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.servlet.DispatcherServlet.doDispatch
(DispatcherServlet.java:1040
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.servlet.DispatcherServlet.doService
(DispatcherServlet.java:943
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.servlet.FrameworkServlet.processRequest
(FrameworkServlet.java:1006
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.servlet.FrameworkServlet.doPost
(FrameworkServlet.java:909
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at javax.servlet.http.HttpServlet.service
(HttpServlet.java:652
) [tomcat-embed-core-9.0.37.jar
!/:4.0.FR
]at org.springframework.web.servlet.FrameworkServlet.service
(FrameworkServlet.java:883
) [spring-webmvc-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at javax.servlet.http.HttpServlet.service
(HttpServlet.java:733
) [tomcat-embed-core-9.0.37.jar
!/:4.0.FR
]at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
(ApplicationFilterChain.java:231
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:166
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.tomcat.websocket.server.WsFilter.doFilter
(WsFilter.java:53
) [tomcat-embed-websocket-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
(ApplicationFilterChain.java:193
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:166
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.springframework.web.filter.RequestContextFilter.doFilterInternal
(RequestContextFilter.java:100
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.filter.OncePerRequestFilter.doFilter
(OncePerRequestFilter.java:119
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
(ApplicationFilterChain.java:193
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:166
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.springframework.web.filter.FormContentFilter.doFilterInternal
(FormContentFilter.java:93
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.filter.OncePerRequestFilter.doFilter
(OncePerRequestFilter.java:119
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
(ApplicationFilterChain.java:193
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:166
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal
(CharacterEncodingFilter.java:201
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.springframework.web.filter.OncePerRequestFilter.doFilter
(OncePerRequestFilter.java:119
) [spring-web-5.2.8.RELEASE.jar
!/:5.2.8.RELEASE
]at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
(ApplicationFilterChain.java:193
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:166
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.StandardWrapperValve.invoke
(StandardWrapperValve.java:202
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.StandardContextValve.invoke
(StandardContextValve.java:96
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.authenticator.AuthenticatorBase.invoke
(AuthenticatorBase.java:541
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.StandardHostValve.invoke
(StandardHostValve.java:139
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.valves.ErrorReportValve.invoke
(ErrorReportValve.java:92
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.core.StandardEngineValve.invoke
(StandardEngineValve.java:74
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.catalina.connector.CoyoteAdapter.service
(CoyoteAdapter.java:343
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.coyote.http11.Http11Processor.service
(Http11Processor.java:373
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.coyote.AbstractProcessorLight.process
(AbstractProcessorLight.java:65
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.coyote.AbstractProtocol
$ConnectionHandler.process
(AbstractProtocol.java:868
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.tomcat.util.net.NioEndpoint
$SocketProcessor.doRun
(NioEndpoint.java:1589
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at org.apache.tomcat.util.net.SocketProcessorBase.run
(SocketProcessorBase.java:49
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at java.util.concurrent.ThreadPoolExecutor.runWorker
(ThreadPoolExecutor.java:1149
) [na:1.8.0_171
]at java.util.concurrent.ThreadPoolExecutor
$Worker.run
(ThreadPoolExecutor.java:624
) [na:1.8.0_171
]at org.apache.tomcat.util.threads.TaskThread
$WrappingRunnable.run
(TaskThread.java:61
) [tomcat-embed-core-9.0.37.jar
!/:9.0.37
]at java.lang.Thread.run
(Thread.java:748
) [na:1.8.0_171
]
Caused by: redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketException: 打開的文件過多at redis.clients.jedis.Connection.connect
(Connection.java:207
) ~
[jedis-2.9.0.jar
!/:na
]at redis.clients.jedis.BinaryClient.connect
(BinaryClient.java:93
) ~
[jedis-2.9.0.jar
!/:na
]at redis.clients.jedis.BinaryJedis.connect
(BinaryJedis.java:1767
) ~
[jedis-2.9.0.jar
!/:na
]at redis.clients.jedis.JedisFactory.makeObject
(JedisFactory.java:106
) ~
[jedis-2.9.0.jar
!/:na
]at org.apache.commons.pool2.impl.GenericObjectPool.create
(GenericObjectPool.java:899
) ~
[commons-pool2-2.8.0.jar
!/:2.8.0
]at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject
(GenericObjectPool.java:429
) ~
[commons-pool2-2.8.0.jar
!/:2.8.0
]at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject
(GenericObjectPool.java:354
) ~
[commons-pool2-2.8.0.jar
!/:2.8.0
]at redis.clients.util.Pool.getResource
(Pool.java:49
) ~
[jedis-2.9.0.jar
!/:na
]...
63 common frames omitted
Caused by: java.net.SocketException: 打開的文件過多at java.net.Socket.createImpl
(Socket.java:460
) ~
[na:1.8.0_171
]at java.net.Socket.getImpl
(Socket.java:520
) ~
[na:1.8.0_171
]at java.net.Socket.setReuseAddress
(Socket.java:1449
) ~
[na:1.8.0_171
]at redis.clients.jedis.Connection.connect
(Connection.java:174
) ~
[jedis-2.9.0.jar
!/:na
]...
70 common frames omitted
緊急處理
- 由于這個是操作系統對用戶啟動單個進程作的限制（配置是針對用戶，用ulimit -a可查看）；默認為1024個。
配置查看
通過 ulimit -a 配合 lsof -p $(jps -l | grep ‘uid’ | awk ‘{print $1}’) | wc -l 查看
cat /proc/$(jps -l | grep ‘uid’ | awk ‘{print $1}’)/limits，其中uid為服務查找關鍵詞
[root@ejy-kf2-jyxt2 ~
]
Limit Soft Limit Hard Limit Units
...
Max
open files
1024 1024 files
...
處理方法
重啟應用，優先保證服務可用性（適合由于長期運行導致，fd累計增多達到上限【此處適用】）。應用確實需要比較多的fd（最典型的例子就是ES服務了，它需要同時操作大量磁盤文件達到很高的IOPS），修改/etc/security/limits.conf文件，重啟或sysctl -p后生效。
[root@demo ~
]
...
* soft nofile
204800
* hard nofile
204800
...
根原排查
- 經過 緊急處理 處理后服務暫時可用，但是根本原因還不得而知；和同事討論后得知此服務已經正常運行1年半左右，且中間沒有重啟過。結合fd的產生原因以及這個服務本身只是負責產生全局的id，應該不存在大量的文件操作和網絡操作；如此的話不應該會觸及系統默認1024個fd的限制才對。
代碼定位
- 從日志的異常棧中 at redis.clients.jedis.JedisFactory.makeObject(JedisFactory.java:106) ~[jedis-2.9.0.jar!/:na] 提示找到Redis獲取鏈接的方法。
public class UidServiceImpl implements IUidService {private static Jedis jedis
= null;private static String confname
= null;static {confname
= ResourceBundle.getBundle("conf").getString("confname");Setting setting
= new Setting("config/redis-" + Lists.newArrayList(Splitter.on("_").split(confname
)).get(1) + ".setting");jedis
= RedisDS.create(setting
,null).getJedis();System.out
.println("已連接上redis");}private void connectRedis(){confname
= ResourceBundle.getBundle("conf").getString("confname");Setting setting
= new Setting("config/redis-" + Lists.newArrayList(Splitter.on("_").split(confname
)).get(1) + ".setting");jedis
= RedisDS.create(setting
,null).getJedis();System.out
.println("已連接上redis");}@Overridepublic synchronized Integer nextNoticeId() {String noticeIdKey
= confname
+ "_" + IdKeyEnum.NOTICE
.getkey();String idStr
= null;try {idStr
= jedis
.get(noticeIdKey
);}catch (Exception e
){connectRedis();idStr
= jedis
.get(noticeIdKey
);}if(idStr
==null){try {idStr
= Convert.toStr(initServiceImpl
.initNoticeIdStartValue());jedis
.set(noticeIdKey
, idStr
);jedis
.incr(noticeIdKey
);System.out
.println(LocalDateTime.now().toString() + "noticeid\t" + jedis
.get(noticeIdKey
));return Convert.toInt(idStr
) + 1;} catch (Exception e
) {e
.printStackTrace();return null;}}else{jedis
.incr(noticeIdKey
);System.out
.println(LocalDateTime.now().toString() + "noticeid\t" + jedis
.get(noticeIdKey
));return Convert.toInt(idStr
) + 1;}}
}
try {idStr
= jedis
.get(noticeIdKey
);
} catch (Exception e
){connectRedis();idStr
= jedis
.get(noticeIdKey
);
}
復現問題
- 在測試環境發布一個測試用的項目，并通過重啟redis服務來觸發jedis.get方法的異常，使其走到connectRedis方法中
重啟Redis服務
[root@VM-4-3-centos ~
]
myredis
[root@VM-4-3-centos ~
]
myredis
[root@VM-4-3-centos ~
]
myredis
[root@VM-4-3-centos ~
]
myredis
[root@VM-4-3-centos ~
]
myredis
調用服務的/uid/notice/nextid接口（觸發nextNoticeId方法）并查看fd【25932 為對應的】
[root@ejy-kf2-jyxt2 ~
]
25932 uid-distribute-0.0.1-SNAPSHOT.jar
[root@ejy-kf2-jyxt2 ~
]
81
[root@ejy-kf2-jyxt2 ~
]
83
[root@ejy-kf2-jyxt2 ~
]
84
[root@ejy-kf2-jyxt2 ~
]
85
[root@ejy-kf2-jyxt2 ~
]
86
查看具體的fd占用情況 lsof -p $(jps -l | grep uid) | wc -l，發現未釋放的鏈接池產生的fd變成了sock還存在
代碼改造
- 獲取鏈接之前把老的 Jedis鏈接 以及 RedisDS 關閉。
public class UidServiceImpl implements IUidService {private static RedisDS redisDS
= null;private static Jedis jedis
= null;private static String confname
= null;static {confname
= ResourceBundle.getBundle("conf").getString("confname");Setting setting
= new Setting("config/redis-" + Lists.newArrayList(Splitter.on("_").split(confname
)).get(1) + ".setting");jedis
= RedisDS.create(setting
,null).getJedis();System.out
.println("已連接上redis");}private void connectRedis(){if (null != jedis
) {System.out
.println("關閉jedis連接");jedis
.close();}if (null != redisDS
) {try {System.out
.println("關閉連接池");redisDS
.close();} catch (IOException ex
) {ex
.printStackTrace();}}confname
= ResourceBundle.getBundle("conf").getString("confname");Setting setting
= new Setting("config/redis-" + Lists.newArrayList(Splitter.on("_").split(confname
)).get(1) + ".setting");redisDS
= RedisDS.create(setting
,null);jedis
= redisDS
.getJedis();System.out
.println("已連接上redis");}
}
[root@ejy-kf2-jyxt2 ~
]
77
[root@ejy-kf2-jyxt2 ~
]
77
[root@ejy-kf2-jyxt2 ~
]
77
- 查看具體的fd占用情況，fd一直保持在35u沒有新增
總結
這是一個由于鏈接資源沒有關閉而導致的內存泄漏的實際案例。代碼有待優化，這里雖然初始化了redis連接池，然而并沒有用到連接池的功能。思考為什么鏈接斷開后鏈接池沒有檢測到鏈接斷開從而自動執行close動作。這里我并沒有完整復現Too many open files現象，有興趣的同學可以把ulimit調小試下能否完整復現出線上的問題場景。
總結
以上是生活随笔為你收集整理的排查【Jedis客户端触发 Too many open files 问题】的全部內容，希望文章能夠幫你解決所遇到的問題。
如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。
