首页 > 代码库 > sentinel服务器出现大量的连接问题【转载】
sentinel服务器出现大量的连接问题【转载】
一、问题现象
- redis服务端的sentinel模块存在大量的established状态的连接,并且这些连接一直不被释放,而客户端的连接数正常。
二、问题排查过程
1、根据连接状态进行推断
- 服务端存在大量的连接的状态为established,而客户端连接数正常,这说明客户端连接是被非正常的方式关闭的,因为根据TCP关闭连接的四次握手协议来看,只要客户端正常发起了关闭动作,服务端的状态只可能为CLOSE_WAIT/LAST_ACK/CLOSED中的一种。
- 非正常关闭连接的情况有断电、断网后服务器重启等等,但这些场景出现的次数较少,不会造成这么多连接,究竟是怎样被正常关闭,到这一步还无法判断,只能先从其它方面入手。
2、检查业务系统的redis配置和程序逻辑
- 检查redis配置,看是否有不规范的配置和不规范的使用redis的代码,经过排查,确定openapi有直接使用JedisSentinelPool类,但并未在spring中配置destroy-method=”destroy”,即在停止应用时释放连接。
- 排查其它系统,未发现有不正常使用redis的情况,JedisSentinelPool造成的连接数增长也是有限的,即只在启动时才创建sentinel连接,此处暂时排查是业务代码使用redis不规范的问题。
3、从网络寻找线索
- 通过百度搜索,找不到关于sentinel的该问题的文章。
- 查看redis、jedis、spring-data-redis官方网站的issues及releaseNotes,均未发现有提及该问题。
4、重新思考产生连接的根源
- 通过阅读jedis源码,发现连接sentinel的代码只有1处,即系统启动时会先建立一个短连接查询sentinel的主节点,然后开启3(业务系统配置了3个地址)个线程创建3个长连接与3个sentinel相连。短连接会立即释放,而长连接的创建放在循环中,问题可能出现在该处,以下是源码:
public void run() {
running.set(true);
while (running.get()) {
j = new Jedis(host, port);
try {
j.subscribe(new JedisPubSub() {
@Override
public void onMessage(String channel, String message) {
log.fine("Sentinel " + host + ":" + port + " published: " + message + ".");
String[] switchMasterMsg = message.split(" ");
if (switchMasterMsg.length > 3) {
if (masterName.equals(switchMasterMsg[0])) {
initPool(toHostAndPort(Arrays.asList(switchMasterMsg[3], switchMasterMsg[4])));
} else {
log.fine("Ignoring message on +switch-master for master name "
+ switchMasterMsg[0] + ", our master name is " + masterName);
}
} else {
log.severe("Invalid message received on Sentinel " + host + ":" + port
+ " on channel +switch-master: " + message);
}
}
}, "+switch-master");
} catch (JedisConnectionException e) {
if (running.get()) {
log.severe("Lost connection to Sentinel at " + host + ":" + port
+ ". Sleeping 5000ms and retrying.");
try {
Thread.sleep(subscribeRetryWaitTimeMillis);
} catch (InterruptedException e1) {
e1.printStackTrace();
}
} else {
log.fine("Unsubscribing from Sentinel at " + host + ":" + port);
}
}
}
}
正常情况下 j.subscribe会产生阻塞,而出现异常时会重新创建连接并且打印日志“Lost connection to Sentinel at……”
- 在业务系统搜索“Lost connection to Sentinel at”日志,把所有业务日志都搜索一遍,没有找到该日志,最后终于在nohub日志中找到了(nohub日志在weblogic启动时会被清理,也导致找了几次才找到该日志),通过UltraEdit提取所有该内容的日志,发现了28条日志,将这些日志导出到excel比较,发现日志出现的时间间隔均为2小时11分15秒到2小时11分20秒左右,该日志出现的时间间隔非常有规律,这种规律一定与该问题存在某种联系。
一般在系统中设置时间间隔都会是个整数,2小时11分15秒显得有点怪异,然后将时间换算成秒,看是否为一个常用的或有规律的整数,2小时=7200秒,突然想到操作系统的keepalive设置中有一个7200秒,查一下操作系统默认的设置,参数如下:
net.ipv4.tcp_keepalive_time = 7200 默认 tcp空闲时间
net.ipv4.tcp_keepalive_intvl =75 默认心跳检测时间间隔
net.ipv4.tcp_keepalive_probes = 9 默认检测次数
如果完成9次心跳,仍然发现连接无效的时间为:7200+9*75=2小时11分15秒,由此,基本上可以判断,客户端的连接是被操作系统回收的,结合前面的分析,连接被回收时并未向服务端发送关闭的报文。
- 通过在网络上搜索,长连接被阻断的原因,看到了防火墙的字样,进一步了解,发现防火墙基本上都有该项功能,即给长连接设置默认的超时时间。
5、与运维进行沟通防火墙问题
- 刚开始问运行同事A时,同事A说防火墙用的是juniper,但绝对没有为长连接设置默认的超时时间。
- 进一步搜索juniper的资料,确定是有默认30分钟的超时时间。
- 与运维同事B沟通,确认有默认的超时时间。防火墙的策略是,当建立连接时,会在防火墙保存一条会话信息,记录了源IP、源端口、目的IP、目的端口。当在超时时间内,该会话代表的连接未有任何数据包时,就会清除该会话,此后若再有数据包过来,由于没有了会话,防火墙会直接丢弃该会话。
- 要同事B将sentinel的端口26379配置一条永不超时的策略。
6、持续观察测试环境的日志
- 发现在更改了防火墙超时策略后,仍然出现了一条“Lost connection to Sentinel at”日志,此后一直未出现,由此可见,防火墙确实对连接造成了影响。
7、初步结论
- 防火墙每30分钟将该连接的会话信息清除,从而导致客户端操作系统检测到心跳失败,随后操作系统清除了客户端连接,使得客户端的连接数能正常释放,由于报文被防火墙丢弃,close信息也不会到达服务端,导致服务端的连接未被及时关闭。
8、继续思考服务断连接不被释放的问题
- 按道理连接被防火墙阻断后,既然客户端的操作系统能正常回收连接,服务端应该也可以,但服务端的keepalive机制为什么没有发生作用?通过进一步阅读redis客户端-jedis的源码,发现jedis默认开启了keepalive,继续阅读redis的源码,发现redis默认关闭了keepalive,到此所有疑问已经解决。
以上因素使得防火墙每30分钟将该连接的会话信息清除,从而导致客户端操作系统检测到心跳失败,随后操作系统清除了客户端连接,使得客户端的连接数能正常释放,随后客户端的jedis收到异常后重新创建连接,而服务端的keepalive并未执行,以上过程不断循环,导致服务端established状态的连接不断增加并得不到释放。
sentinel服务器出现大量的连接问题【转载】