记一次连接Redis偶现超时的问题

参考：https://www.phpmianshi.com/?id=118

问题描述

 

公司老的项目没有任何监控，对于系统的运行健康情况完全不知，于是搭建了2套监控系统，一套sentry监控代码层面的exception，一套cls告警，监控所有系统的状态码，应用日志等。监控系统上线后，就发现有一台跑定时任务的机器，经常偶现报错 RedisException: Connection timed out,一天几十次，也不是固定时间，如下图：

 

 

问题分析

 

于是开始分析为何超时，首先想到的是不是tcp连接数过多？于是查看系统tcp链接状态，发现并没有太多连接，timewait也不多

ss -s
Total: 548 (kernel 808)
TCP:   745 (estab 209, closed 531, orphaned 1, synrecv 0, timewait 531/0), ports 0

查看网络统计，问题前后并没有变化

netstat -s |grep reject
    4 passive connections rejected because of time stamp
    52 packets rejects in established connections because of timestamp

 

于是查看发生超时时的系统日志,也没有发现异常

vi /var/log/messages

 

登录腾讯云查看redis监控，发生问题时候的连接数等都没有太大的异常，对比另一台没有报错的redis服务，这个出问题的redis是集群

于是猜想是不是redis集群的问题，不过抱着对大厂产品的信任，还是从自身查起，看是不是自己使用姿势有问题。

先从最简单的方法入手，修改链接redis前后的代码，增加时间戳记录，判断到底那个地方超时了

monolog("start",time());
Redis::connection('redis_db_4');
monolog("end",time());

部署上线观察，发现就是这地方connection 超时了，难道是网络问题？按理说都是腾讯家的服务，不应该存在这么频繁的网络问题啊

 

继续查看sentry日志：

发现超时时间基本是60s， 正好是php.ini下面socket的超时时间

default_socket_timeout=60

 

既然怀疑网络问题，那我们就抓包分析吧，因为是偶现问题，我们只能持续抓包，没过一段时间过来看下是否有新超时了。

 

tcpdump抓包分析结果：

09:13:02.104349 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132733115 ecr
0,nop,wscale 7], length 0
09:13:03.104847 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132734116 ecr
0,nop,wscale 7], length 0
09:13:05.108833 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132736120 ecr
0,nop,wscale 7], length 0
09:13:09.116833 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132740128 ecr
0,nop,wscale 7], length 0
09:13:17.132842 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132748144 ecr
0,nop,wscale 7], length 0
09:13:33.148834 IP phpmianshi.com.42548 > 10.66.151.82.6379: Flags
 [S], seq 2777158311, win 29200, options [mss 1460,sackOK,TS val 1132764160 ecr
0,nop,wscale 7], length 0

 

抓包发现三次握手 发了SYN   Redis没有 ACK回复，然后5次重传都没有回复，仿佛这时候我们就有点无从查起了，毕竟redis是云服务，咱们也没法上去抓包

 

看来只能提工单了，抓包分析结果提给腾讯云客服，经过跟腾讯云持续一周左右的沟通（此处省略10000字...）

1.为了排除是机器硬件问题，腾讯云给迁移了机器  （未能解决问题）

2.服务端不回复ack参考文章： 

https://m.163yun.com/help/documents/230866483626037248

不过这是修改服务端的，咱们虽然是服务器，但是相对于链接redis来说，咱们属于客户端，我也尝试按照上面方法修改咱们的服务器，并不管用

3.升级后端客服（网络、服务器、mem等技术后端一起排查问题），最后发现是redis集群有些问题

于是在某个夜黑风高的凌晨00:11分左右，腾讯云redis集群升级，伴随着持续几秒的 NOAUTH Authentication required.   或者 Connection refused 报警后，发现链接超时的问题消失了。

持续观察2天，发现从此再没出现过链接超时的问题。

4.这个故事也告诉我们，大厂服务也不一定完全是稳定的，毕竟都是工程师做的东西，非常理解，在此感谢腾讯各部门工程师的辛苦工作，解决了困扰我们很久的一个问题。