Redis偶发连接失败案例实战记录_Redis_

前言

本文主要给大家介绍了关于Redis偶发连接失败的相关内容，分享出来供大家参考学习，下面话不多说了，来一起看看详细的介绍吧

【作者】

张延俊：携程技术保障中心资深DBA，对数据库架构和疑难问题分析排查有浓厚的兴趣。

寿向晨：携程技术保障中心高级DBA，主要负责携程Redis及DB的运维工作，在自动化运维，流程化及监控排障等方面有较多的实践经验，喜欢深入分析问题，提高团队运维效率。

【问题描述】

 生产环境有一个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前后的网络包进行明细分析，网络包来往情况如下：

12:01:54.6808480, Redis Server端向客户端发送了一个Push包，也就是对于查询请求的一个结果返回。后面的包都是在做连接处理，包括Ack包，Ack确认包，以及重置的RST包，紧接着下面一个Push包是在12:01:56.1181350发出的。中间的间隔是1.4372870秒。也就是说，在这1.4372870秒期间，Redis的服务器端，除了做一个查询，其他的操作都是在做建连，或拒绝连接。

客户端报错的前后逻辑已经清楚了，redis-server卡了1.43秒，client的connection pool被打满，疯狂新建连接，server的accept queue满，直接拒绝服务，client报错。开始怀疑client发送了特殊命令，这时需要确认一下client的最后几个命令是什么，找到redis-server卡死前的第一个包，装一个wireshark的redis插件，看到最后几个命令是简单的get，并且key-value都很小，不至于需要耗费1.43秒才能完成。服务端也没有slow log，此时排障再次陷入僵局。

【进一步分析】

为了了解这1.43秒之内，Redis Server在做什么事情，我们用pstack来抓取信息。Pstack本质上是gdb attach. 高频率的抓取会影响redis的吞吐。死循环0.5秒一次无脑抓，在redis-server卡死的时候抓到堆栈如下(过滤了没用的栈信息)：

Thu May 31 11:29:18 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP 8378)):
#0 0x000000000048cec4 in ?? ()
#1 0x00000000004914a4 in je_arena_ralloc ()
#2 0x00000000004836a1 in je_realloc ()
#3 0x0000000000422cc5 in zrealloc ()
#4 0x00000000004213d7 in sdsRemoveFreeSpace ()
#5 0x000000000041ef3c in clientsCronResizeQueryBuffer ()
#6 0x00000000004205de in clientsCron ()
#7 0x0000000000420784 in serverCron ()
#8 0x0000000000418542 in aeProcessEvents ()
#9 0x000000000041873b in aeMain ()
#10 0x0000000000420fce in main ()
Thu May 31 11:29:19 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP 8378)):
#0 0x0000003729ee5407 in madvise () from /lib64/libc.so.6
#1 0x0000000000493a4e in je_pages_purge ()
#2 0x000000000048cf70 in ?? ()
#3 0x00000000004914a4 in je_arena_ralloc ()
#4 0x00000000004836a1 in je_realloc ()
#5 0x0000000000422cc5 in zrealloc ()
#6 0x00000000004213d7 in sdsRemoveFreeSpace ()
#7 0x000000000041ef3c in clientsCronResizeQueryBuffer ()
#8 0x00000000004205de in clientsCron ()
#9 0x0000000000420784 in serverCron ()
#10 0x0000000000418542 in aeProcessEvents ()
#11 0x000000000041873b in aeMain ()
#12 0x0000000000420fce in main ()
Thu May 31 11:29:19 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP 8378)):
#0 0x000000000048108c in je_malloc_usable_size ()
#1 0x0000000000422be6 in zmalloc ()
#2 0x00000000004220bc in sdsnewlen ()
#3 0x000000000042c409 in createStringObject ()
#4 0x000000000042918e in processMultibulkBuffer ()
#5 0x0000000000429662 in processInputBuffer ()
#6 0x0000000000429762 in readQueryFromClient ()
#7 0x000000000041847c in aeProcessEvents ()
#8 0x000000000041873b in aeMain ()
#9 0x0000000000420fce in main ()
Thu May 31 11:29:20 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP 8378)):
#0 0x000000372a60e7cd in write () from /lib64/libpthread.so.0
#1 0x0000000000428833 in sendReplyToClient ()
#2 0x0000000000418435 in aeProcessEvents ()
#3 0x000000000041873b in aeMain ()
#4 0x0000000000420fce in main ()

重复多次抓取后，从堆栈中发现可疑堆栈clientsCronResizeQueryBuffer位置，属于serverCron()函数下，这个redis-server内部的定时调度，并不在用户线程下，这个解释了为什么卡死的时候没有出现慢查询。

查看redis源码，确认到底redis-server在做什么：

 clientsCron(server.h): #define CLIENTS_CRON_MIN_ITERATIONS 5 void clientsCron(void) { /* Make sure to process at least numclients/server.hz of clients * per call. Since this function is called server.hz times per second * we are sure that in the worst case we process all the clients in 1 * second. */ int numclients = listLength(server.clients); int iterations = numclients/server.hz; mstime_t now = mstime(); /* Process at least a few clients while we are at it, even if we need * to process less than CLIENTS_CRON_MIN_ITERATIONS to meet our contract * of processing each client once per second. */ if (iterations < CLIENTS_CRON_MIN_ITERATIONS) iterations = (numclients < CLIENTS_CRON_MIN_ITERATIONS) ? numclients : CLIENTS_CRON_MIN_ITERATIONS; while(listLength(server.clients) && iterations--) { client *c; listNode *head; /* Rotate the list, take the current head, process. * This way if the client must be removed from the list it's the * first element and we don't incur into O(N) computation. */ listRotate(server.clients); head = listFirst(server.clients); c = listNodeValue(head); /* The following functions do different service checks on the client. * The protocol is that they return non-zero if the client was * terminated. */ if (clientsCronHandleTimeout(c,now)) continue; if (clientsCronResizeQueryBuffer(c)) continue; } }

clientsCron首先判断当前client的数量，用于控制一次清理连接的数量，生产服务器单实例的连接数量在5000不到，也就是一次清理的连接数是50个。

 clientsCronResizeQueryBuffer(server.h): /* The client query buffer is an sds.c string that can end with a lot of * free space not used, this function reclaims space if needed. * * The function always returns 0 as it never terminates the client. */ int clientsCronResizeQueryBuffer(client *c) { size_t querybuf_size = sdsAllocSize(c->querybuf); time_t idlet
                
提示：
                    本文由神整理自网络，如有侵权请联系本站删除！
                    

                    本站声明： 

                    1、本站所有资源均来源于互联网，不保证100%完整、不提供任何技术支持； 

                    2、本站所发布的文章以及附件仅限用于学习和研究目的;不得将用于商业或者非法用途；否则由此产生的法律后果，本站概不负责！
                
                

                

                                            
上一篇：Redis命令使用技巧之Keys的相关操作_Redis_
                                                                
下一篇：Redis如何使用lua脚本实例教程_Redis_