欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页  >  IT编程

redis连接未释放,导致redis连接池满,从而应用服务不可用的问题定位和解决

程序员文章站 2022-03-13 09:09:40
版本提交测试验收后,跑了几天,今天测试突然跑来说平台不可用。 1. 我先是试图登录平台,发现首页可以进入,但是登录不成功。很显然是后台的问题。...

版本提交测试验收后,跑了几天,今天测试突然跑来说平台不可用。

1. 我先是试图登录平台,发现首页可以进入,但是登录不成功。很显然是后台的问题。

2. 再看MQ中,发现消息堆积在队列中,未被消费掉,同时一点一点变化,说明很有可能是哪里有内存或连接的泄露或未释放。

3. 接着登录阿里云账号,查看redis监控,发现连接数已经达到9000多。

4. 查看日志发现大量的redis连接拒绝错误

redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
at redis.clients.util.Pool.getResource(Pool.java:42)
at redis.clients.jedis.JedisPool.getResource(JedisPool.java:84)
at com.***(**.java:58)
at com.***(**.java:86)
at com.***(**.java:27)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
at org.apache.log4j.Category.callAppenders(Category.java:206)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.log(Category.java:856)
at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:571)
at com.***(**.java:61)
at com.***(**.java:86)
at com.***(**.java:27)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
at org.apache.log4j.Category.callAppenders(Category.java:206)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.log(Category.java:856)
at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:571)
at com.***(**.java:61)
at com.***(**.java:86)
at com.***(**.java:27)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)

5. 当然后台的tomcat中也报了其他错误,比如:

Exception in thread "Thread-18" java.lang.*Error
        at java.util.Hashtable.get(Hashtable.java:367)
        at java.util.Properties.getProperty(Properties.java:969)
        at java.lang.System.getProperty(System.java:720)
        at sun.security.action.GetPropertyAction.run(GetPropertyAction.java:86)
        at sun.security.action.GetPropertyAction.run(GetPropertyAction.java:52)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.io.PrintWriter.<init>(PrintWriter.java:116)
        at java.io.PrintWriter.<init>(PrintWriter.java:100)
        at org.apache.log4j.DefaultThrowableRenderer.render(DefaultThrowableRenderer.java:58)
        at org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInformation.java:87)
        at com.aliyun.openservices.log.log4j.LoghubAppender.append(LoghubAppender.java:116)
        at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
        at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
        at org.apache.log4j.Category.callAppenders(Category.java:206)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.log(Category.java:856)
        at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:571)
        at com.***(**.java:61)
        at com.***(**.java:86)
        at com.***(**.java:27)
        at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
        at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
        at org.apache.log4j.Category.callAppenders(Category.java:206)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.log(Category.java:856)

6. 但是,还是继续查看日志,发现一直有个 [TaskId]PUPHVUNVJSSMKOTQPKHRSPOMUKKOKLPG [Message]null [Result]0 debug日志,因为只有一直不停的发,且连接不关闭才可能出现这么多连接的情况。一边对应代码,发现是页面上调用后台代码,发送给设备长连接的代码。

try{
   for(...)
   {   
       jedis = RedisManagerPool.getJedis();
       if(!"NULL".equals(value)) {
           break;
       }
	   RedisUtils.return(jedis);
   }
} catch() {
   logger.error();
   RedisUtils.returnBroken(jedis);
} 
return value; 

且try中没有finally块,很显然如果条件满足的话就直接break,并return value。但是RedisUtils.return(jedis)这条语句就未执行。然后进一步怀疑页面是否是定时去获取,通过F12,发现每10s钟请求一次,页面上要获取设备的上下行速率。所以会累积这么多的请求。最后,修改也比较简单,添加finally块,保证RedisUtils.return(jedis)必定会执行。

8. 接下来在另一个开发环境继续复现,我们将redisManagerPool中设置maxTotal=300,maxIdle=30。而原先是3000、300,这样有利于快速复现。
果然,一上午时间就达到了300的限制。出现了一样的问题。

9. 综上,问题定位清楚,且修复该问题。
a) 对于oss redis之类的第三方网络连接,必须要有finally块执行。否则后续很容易由于不规范的编码,出现这种连接未正常释放的问题。
b) 定位问题,还是需要有日志。如果单从代码去查,方向会比较多且很容易浪费时间。
c) 修改池大小,缩短复现时间,快速定位修改。

转载于:https://my.oschina.net/beyondken/blog/3016174