Redis偶发连接失败案例分析

 生产环境有一个Redis会偶尔发生连接失败的报错，报错的时间点、客户端IP并没有特别明显的规律，过一会儿，报错会自动恢复。
 以下是客户端报错信息：

CRedis.Client.RExceptions.ExcuteCommandException: Unable to Connect redis server: ---> CRedis.Third.Redis.RedisException: Unable to Connect redis server: 在 CRedis.Third.Redis.RedisNativeClient.CreateConnectionError() 在 CRedis.Third.Redis.RedisNativeClient.SendExpectData(Byte[][] cmdWithBinaryArgs) 在 CRedis.Client.Entities.RedisServer.<>c__DisplayClassd`1.

 从报错的信息来看，应该是连接不上Redis所致。Redis的版本是2.8.19。虽然版本有点老，但基本运行稳定。
 线上环境只有这个集群有偶尔报错。这个集群的一个比较明显的特征是客户端服务器比较多，有上百台。

【问题分析】

 从报错的信息来看，客户端连接不到服务端。常见的原因有以下几点：

一个常见的原因是由于端口耗尽，对网络连接进行排查，在出问题的点上，TCP连接数远没有达到端口耗尽的场景，因此这个不是Redis连接不上的根本原因。

另外一种常见的场景是在服务端有慢查询，导致Redis服务阻塞。我们在Redis服务端，把运行超过10毫秒的语句进行抓取，也没有抓到运行慢的语句。

 从服务端的部署的监控来看，出问题的点上，连接数有一个突然飙升，从3500个连接突然飙升至4100个连接。如下图显示：

同时间，服务器端显示Redis服务端有丢包现象：345539 – 344683 = 856个包。

Sat Apr 7 10:41:40 CST 2018 1699 outgoing packets dropped 92 dropped because of missing route 344683 SYNs to LISTEN sockets dropped 344683 times the listen queue of a socket overflowed Sat Apr 7 10:41:41 CST 2018 1699 outgoing packets dropped 92 dropped because of missing route 345539 SYNs to LISTEN sockets dropped 345539 times the listen queue of a socket overflowed

 客户端报错的原因基本确定，是因为建连速度太快，导致服务端backlog队列溢出，连接被server端reset。

【关于backlog overflow】

 在高并发的短连接服务中，这是一种很常见的tcp报错类型。一个正常的tcp建连过程如下：

 1.client发送一个(SYN)给server

 2.server返回一个(SYN,ACK)给client

 3.client返回一个(ACK)

 三次握手结束，对client来说建连成功，client可以继续发送数据包给server，但是这个时候server端未必ready，如下图所示 ：

在BSD版本内核实现的tcp协议中，server端建连过程需要两个队列，一个是SYN queue，一个是accept queue。前者叫半开连接（或者半连接）队列，在接收到client发送的SYN时加入队列。（一种常见的网络攻击方式就是不断发送SYN但是不发送ACK从而导致server端的半开队列撑爆，server端拒绝服务。）后者叫全连接队列，server返回(SYN,ACK)，在接收到client发送ACK后（此时client会认为建连已经完成，会开始发送PSH包），如果accept queue没有满，那么server从SYN queue把连接信息移到accept queue；如果此时accept queue溢出的话，server的行为要看配置。如果tcp_abort_on_overflow为0（默认），那么直接drop掉client发送的PSH包，此时client会进入重发过程，一段时间后server端重新发送SYN,ACK，重新从建连的第二步开始；如果tcp_abort_on_overflow为1，那么server端发现accept queue满之后直接发送reset。

通过wireshark搜索发现在一秒内有超过2000次对Redis Server端发起建连请求。我们尝试修改tcp backlog大小，从511调整到2048, 问题并没有得到解决。所以此类微调，并不能彻底的解决问题。

【网络包分析】

我们用wireshark来识别网络拥塞的准确时间点和原因。我们已经有了准确的报错时间点，先用editcap把超大的tcp包裁剪一下，裁成30秒间隔，并通过wireshark I/O 100ms间隔分析网络阻塞的准确时间点：

 根据图标可以明显看到tcp的packets来往存在block。

 对该block前后的网络包进行明细分析，网络包来往情况如下：

TimeSourceDestDescription
  12:01:54.6536050       Redis-Server       Clients       TCP:Flags=…AP…  
  12:01:54.6538580       Redis-Server       Clients       TCP:Flags=…AP…  
  12:01:54.6539770       Redis-Server       Clients       TCP:Flags=…AP…  
  12:01:54.6720580       Redis-Server       Clients       TCP:Flags=…A..S..  
  12:01:54.6727200       Redis-Server       Clients       TCP:Flags=…A……  
  12:01:54.6808480       Redis-Server       Clients       TCP:Flags=…AP…..  
  12:01:54.6910840       Redis-Server       Clients       TCP:Flags=…A…S.,  
  12:01:54.6911950       Redis-Server       Clients       TCP:Flags=…A……  
  …        …         …         …  
  12:01:56.1181350       Redis-Server       Clients       TCP:Flags=…AP….