记一次mongodb核心集群雪崩故障分析

时间 2020-10-18 标签 java linux git github 算法 mongodb 数据库后端缓存服务器

记一次mongodb核心集群雪崩故障分析

关于做者
前滴滴出行技术专家，现任OPPO文档数据库mongodb负责人，负责oppo千万级峰值TPS/十万亿级数据量文档数据库mongodb内核研发及运维工做，一直专一于分布式缓存、高性能服务端、数据库、中间件等相关研发。Github帐号地址:https://github.com/y123456yzjava

1. 问题背景
某核心JAVA长链接服务使用mongodb做为主要存储，客户端数百台机器链接同一mongodb集群，短时间内出现屡次性能抖动问题，此外，还出现一次“雪崩”故障，同时流量瞬间跌零，没法自动恢复。本文分析这两次故障的根本缘由，包括客户端配置使用不合理、mongodb内核连接认证不合理、代理配置不全等一系列问题，最终通过多方努力肯定问题根源。
该集群有十来个业务接口访问，每一个接口部署在数十台业务服务器上面，访问该mongodb机器的客户端总数超过数百台，部分请求一次拉取数十行甚至百余行数据。
该集群为2机房同城多活集群(选举节不消耗太多资源，异地的第三机房来部署选举节点)，架构图以下：

从上图能够看出，为了实现多活，在每一个机房都部署有对应代理，对应机房客户端连接对应机房的mongos代理，每一个机房多个代理。代理层部署IP:PORT地址列表(注意：不是真实IP地址)以下：
A机房代理地址列表：1.1.1.1:111,2.2.2.2:1111,3.3.3.3:1111
B机房代理地址列表：4.4.4.4:1111,4.4.4.4:2222
A机房三个代理部署在三台不一样物理机，B机房2个代理部署在同一台物理机。此外，A机房和B机房为同城机房，跨机房访问时延能够忽略。linux

集群存储层和config server都采用一样的架构：A机房(1主节点+1从节点) + B机房(2从节点)+C机房(1个选举节点arbiter)，即2(数据节点)+2(数据节点)+1(选举节点)模式。

该机房多活架构能够保证任一机房挂了，对另外一机房的业务无影响，具体机房多活原理以下：
1.若是A机房挂掉，因为代理是无状态节点，A机房挂掉不会影响B机房的代理。
2.若是A机房挂掉，同时主节点在A机房，这时候B机房的2个数据节点和C机房的选举节点一共三个节点，能够保证新选举须要大于一半以上节点这个条件，因而B机房的数据节点会在短期内选举出一个新的主节点，这样整个存储层访问不受任何影响。git

本文重点分析以下6个疑问点：

1.为何突发流量业务会抖动？
2.为何数据节点没有任何慢日志，可是代理负载缺100%？
3.为什么mongos代理引发数小时的“雪崩”，而且长时间不可恢复？
4.为什么一个机房代理抖动，对应机房业务切到另外一个机房后，仍是抖动？
5.为什么异常时候抓包分析，客户端频繁建链断链，而且同一个连接建链到断链间隔很短？
6.理论上代理就是七层转发，消耗资源更少，相比mongod存储应该更快，为什么mongod存储节点无任何抖动，mongos代理缺有抖动？github

2. 故障过程
2.1 业务偶尔流量高峰，业务抖动？
该集群一段时间内有屡次短暂的抖动，当A机房客户端抖动后，发现A机房对应代理负载很高，因而切换A机房访问B机房代理，可是切换后B机房代理一样抖动，也就是多活切换没有做用，具体过程分析以下。
2.1.1 存储节点慢日志分析
首先，分析该集群全部mongod存储节点系统CPU、MEM、IO、load等监控信息，发现一切正常，因而分析每一个mongod节点慢日志(因为该集群对时延敏感，所以慢日志调整为30ms)，分析结果以下：算法

从上图能够看出，存储节点在业务抖动的时候没有任何慢日志，所以能够判断存储节点一切正常，业务抖动和mongod存储节点无关。

2.1.2 Mongos代理分析
存储节点没有任何问题，所以开始排查mongos代理节点。因为历史缘由，该集群部署在其余平台，该平台对QPS、时延等监控不是很全，形成早期抖动的时候监控没有及时发现。抖动后，迁移该平台集群到oppo自研的新管控平台，新平台有详细的监控信息，迁移后QPS监控曲线以下：

每一个流量徒增时间点，对应业务监控都有一波超时或者抖动，以下：

分析对应代理mongos日志，发现以下现象：抖动时间点mongos.log日志有大量的建连接和断连接的过程，以下图所示：

从上图能够看出，一秒钟内有几千个连接创建，同时有几千个连接断开，此外抓包发现不少连接短时间内即断开连接，现象以下(断链时间-建链时间=51ms, 部分100多ms断开)：

对应抓包以下：

此外，该机器代理上客户端连接低峰期都很高，甚至超过正常的QPS值，QPS大约7000-8000，可是conn连接缺高达13000，mongostat获取到监控信息以下：

2.1.3 代理机器负载分析
每次突发流量的时候，代理负载很高，经过部署脚本按期采样，抖动时间点对应监控图以下图所示：

从上图能够看出，每次流量高峰的时候CPU负载都很是的高，并且是sy%负载，us%负载很低，同时Load甚至高达好几百，偶尔甚至过千。
2.1.4 抖动分析总结
从上面的分析能够看出，某些时间点业务有突发流量引发系统负载很高。根因真的是由于突发流量吗？其实否则，请看后续分析，这实际上是一个错误结论。没过几天，同一个集群雪崩了。mongodb

因而业务梳理突发流量对应接口，梳理出来后下掉了该接口，QPS监控曲线以下：

为了减小业务抖动，所以下掉了突发流量接口，此后几个小时业务再也不抖动。当下掉突发流量接口后，咱们还作了以下几件事情：
1.因为没找到mongos负载100%真正缘由，因而每一个机房扩容mongs代理，保持每一个机房4个代理，同时保证全部代理在不一样服务器，经过分流来尽可能减小代理负载。
2.通知A机房和B机房的业务配置上全部的8个代理，再也不是每一个机房只配置对应机房的代理(由于第一次业务抖动后，咱们分析mongodb的java sdk，肯定sdk均衡策略会自动剔除请求时延高的代理，下次若是某个代理再出问题，也会被自动剔除)。
3.通知业务把全部客户端超时时间提升到500ms。数据库

可是，内心始终有不少疑惑和悬念，主要在如下几个点：

1.存储节点4个，代理节点5个，存储节点无任何抖动，反而七层转发的代理负载高？
2.为什么抓包发现不少新链接几十ms或者一百多ms后就断开链接了？频繁建链断链？
3.为什么代理QPS只有几万，这时代理CPU消耗就很是高，并且全是sy%系统负载？以我多年中间件代理研发经验，代理消耗的资源不多才对，并且CPU只会消耗us%，而不是sy%消耗。后端

2.2 同一个业务几天后”雪崩”了
好景不长，业务下掉突发流量的接口没过几天，更严重的故障出现了，机房B的业务流量在某一时刻直接跌0了，不是简单的抖动问题，而是业务直接流量跌0，系统sy%负载100%，业务几乎100%超时重连。
2.2.1 机器系统监控分析
机器CPU和系统负载监控以下：

从上图能够看出，几乎和前面的突发流量引发的系统负载太高现象一致，业务CPU sy%负载100%，load很高。登录机器获取top信息，现象和监控一致。

同一时刻对应网络监控以下：

磁盘IO监控以下：

从上面的系统监控分析能够看出，出问题的时间段，系统CPU sy%、load负载都很高，网络读写流量几乎跌0，磁盘IO一切正常，能够看出整个过程几乎和以前突发流量引发的抖动问题彻底一致。
2.2.2 业务如何恢复
第一次突发流量引发的抖动问题后，咱们扩容全部的代理到8个，同时通知业务把全部业务接口配置上全部代理。因为业务接口众多，最终B机房的业务没有配置所有代理，只配置了原先的两个处于同一台物理机的代理(4.4.4.4:1111,4.4.4.4:2222)，最终触发mongodb的一个性能瓶颈(详见后面分析)，引发了整个mongodb集群”雪崩”
最终，业务经过重启服务，同时把B机房的8个代理同时配置上，问题得以解决。缓存

2.2.3 mongos代理实例监控分析
分析该时间段代理日志，能够看出和2.1一样得现象，大量的新键链接，同时新链接在几十ms、一百多ms后又关闭链接。整个现象和以前分析一致，这里不在统计分析对应日志。
此外，分析当时的代理QPS监控，正常query读请求的QPS访问曲线以下，故障时间段QPS几乎跌零雪崩了：

Command统计监控曲线以下：

从上面的统计能够看出，当该代理节点的流量故障时间点有一波尖刺，同时该时间点的command统计瞬间飙涨到22000(实际可能更高，由于咱们监控采样周期30s,这里只是平均值)，也就是瞬间有2.2万个链接瞬间进来了。Command统计其实是db.ismaster()统计，客户端connect服务端成功后的第一个报文就是ismaster报文，服务端执行db.ismaster()后应答客户端，客户端收到后开始正式的sasl认证流程。
正常客户端访问流程以下：
1.客户端发起与mongos的连接
2.Mongos服务端accept接收连接后，连接创建成功
3.客户端发送db.isMaster()命令给服务端
4.服务端应答isMaster给客户端
5.客户端发起与mongos代理的sasl认证(屡次和mongos交互)
6.客户端发起正常的find()流程
客户端SDK连接创建成功后发送db.isMaster()给服务端的目的是为了负载均衡策略和判断节点是什么类型，保证客户端快速感知到访问时延高的代理，从而快速剔除往返时延高的节点，同时肯定访问的节点类型。服务器

此外，经过提早部署的脚本,该脚本在系统负载高的时候自动抓包，从抓包分析结果以下图所示：

上图时序分析以下：

11:21:59.506174连接创建成功
11:21:59.506254 客户端发送db.IsMaster()到服务端
11:21:59.656479 客户端发送FIN断链请求
11:21:59.674717 服务端发送db.IsMaster()应答给客户端
11:21:59.675480 客户端直接RST
第3和第1个报文之间相差大约150ms，最后和业务肯定该客户端IP对应的超时时间配置，肯定就是150ms。此外，其余抓包中有相似40ms、100ms等超时配置，经过对应客户端和业务确认，肯定对应客户端业务接口超时时间配置的就是40ms、100ms等。所以，结合抓包和客户端配置，能够肯定当代理超过指定超时时间尚未给客户端db.isMaster()返回值，则客户端立马超时，超时后立马发起重连请求。

总结：经过抓包和mongos日志分析，能够肯定连接创建后快速断开的缘由是：客户端访问代理的第一个请求db.isMaster()超时了，所以引发客户端重连。重连后又开始获取db.isMaster()请求，因为负载CPU 100%, 很高，每次重连后的请求都会超时。其中配置超时时间为500ms的客户端，因为db.isMaster()不会超时，所以后续会走sasl认证流程。
所以能够看出，系统负载高和反复的建链断链有关，某一时刻客户端大量创建连接(2.2W)引发负载高，又由于客户端超时时间配置不一，超时时间配置得比较大得客户端最终会进入sasl流程，从内核态获取随机数，引发sy%负载高，sy%负载高又引发客户端超时，这样整个访问过程就成为一个“死循环”，最终引发mongos代理雪崩。

2.3 线下模拟故障
到这里，咱们已经大概肯定了问题缘由，可是为何故障突发时间点那一瞬间2万个请求就会引发sy%负载100%呢，理论上一秒钟几万个连接不会引发如此严重的问题，毕竟咱们机器有40个CPU。所以，分析反复建链断链为什么引发系统sy%负载100%就成为了本故障的关键点。
2.3.1 模拟故障过程
模拟频繁建链断链故障步骤以下：
1.修改mongos内核代码，全部请求所有延时600ms
2.同一台机器起两个一样的mongos，经过端口区分
3.客户端启用6000个并发连接，超时时间500ms
经过上面的操做，能够保证全部请求超时，超时后客户端又会立马开始从新建链，再次建链后访问mongodb还会超时，这样就模拟了反复建链断链的过程。此外，为了保证和雪崩故障环境一致，把2个mongos代理部署在同一台物理机。

2.3.2 故障模拟测试结果
为了保证和故障的mongos代理硬件环境一致，所以选择故障一样类型的服务器，而且操做系统版本同样(2.6.32-642.el6.x86_64)，程序都跑起来后，问题立马浮现：

因为出故障的服务器操做系统版本linux-2.6太低，所以怀疑可能和操做系统版本有问题，所以升级同一类型的一台物理机到linux-3.10版本，测试结果以下：

从上图能够看出，客户端6000并发反复重连，服务端压力正常，全部CPU消耗在us%，sy%消耗很低。用户态CPU消耗3个CPU，内核态CPU消耗几乎为0，这是咱们期待的正常结果，所以以为该问题可能和操做系统版本有问题。
为了验证更高并反复建链断链在Linux-3.10内核版本是否有2.6版本一样的sy%内核态CPU消耗高的问题，所以把并发从6000提高到30000，验证结果以下：

测试结果：经过修改mongodb内核版本故意让客户端超时反复建链断链，在linux-2.6版本中，1500以上的并发反复建链断链系统CPU sy% 100%的问题便可浮现。可是，在Linux-3.10版本中，并发到10000后，sy%负载逐步增长，并发越高sy%负载越高。
总结：linux-2.6系统中，mongodb只要每秒有几千的反复建链断链，系统sy%负载就会接近100%。Linux-3.10，并发20000反复建链断链的时候，sy%负载能够达到30%，随着客户端并发增长，sy%负载也相应的增长。Linux-3.10版本相比2.6版本针对反复建链断链的场景有很大的性能改善，可是不能解决根本问题。

2.4 客户端反复建链断链引发sy% 100%根因
为了分析%sy系统负载高的缘由，安装perf获取系统top信息，发现全部CPU消耗在以下接口：
从perf分析能够看出，cpu 消耗在_spin_lock_irqsave函数，继续分析内核态调用栈，获得以下堆栈信息：

89.81% 89.81% [kernel] [k] _spin_lock_irqsave ▒
_spin_lock_irqsave ▒
mix_pool_bytes_extract ▒
extract_buf ▒
extract_entropy_user ▒
urandom_read ▒
vfs_read ▒
sys_read ▒
system_call_fastpath ▒
0xe82d
上面的堆栈信息说明，mongodb在读取 /dev/urandom ，而且因为多个线程同时读取该文件，致使消耗在一把spinlock上。
到这里问题进一步明朗了，故障root case 不是每秒几万的链接数致使sys 太高引发。根本缘由是每一个mongo客户端的新连接会致使mongodb后端新建一个线程，该线程在某种状况下会调用urandom_read 去读取随机数/dev/urandom ，而且因为多个线程同时读取，致使内核态消耗在一把spinlock锁上，出现cpu 高的现象。

2.5 mongodb内核随机数优化
2.5.1 mongodb内核源码定位分析
上面的分析已经肯定，问题根源是mongodb内核多个线程读取/dev/urandom随机数引发，走读mongodb内核代码，发现读取该文件的地方以下：

上面是生成随机数的核心代码，每次获取随机数都会读取”/dev/urandom”系统文件，因此只要找到使用该接口的地方便可便可分析出问题。
继续走读代码，发现主要在以下地方：
//服务端收到客户端sasl认证的第一个报文后的处理，这里会生成随机数
//若是是mongos，这里就是接收客户端sasl认证的第一个报文的处理流程
Sasl_scramsha1_server_conversation::_firstStep(...) {
... ...
unique_ptr<SecureRandom> sr(SecureRandom::create());
binaryNonce[0] = sr->nextInt64();
binaryNonce[1] = sr->nextInt64();
binaryNonce[2] = sr->nextInt64();
... ...
}
//mongos相比mongod存储节点就是客户端，mongos做为客户端也须要生成随机数
SaslSCRAMSHA1ClientConversation::_firstStep(...) {
... ...
unique_ptr<SecureRandom> sr(SecureRandom::create());
binaryNonce[0] = sr->nextInt64();
binaryNonce[1] = sr->nextInt64();
binaryNonce[2] = sr->nextInt64();
... ...
}
2.5.2 mongodb内核源码随机数优化
从2.5.1分析能够看出，mongos处理客户端新链接sasl认证过程都会经过"/dev/urandom"生成随机数，从而引发系统sy% CPU太高，咱们如何优化随机数算法就是解决本问题的关键。
继续分析mongodb内核源码，发现使用随机数的地方不少，其中有部分随机数经过用户态算法生成，所以咱们能够采用一样方法，在用户态生成随机数，用户态随机数生成核心算法以下：
class PseudoRandom {
... ...
uint32_t _x;
uint32_t _y;
uint32_t _z;
uint32_t _w;
}

该算法能够保证产生的数据随机分布，该算法原理详见：
 http://en.wikipedia.org/wiki/Xorshift
 也能够查看以下git地址获取算法实现：
 mongodb随机数生成算法注释

   ** 总结：**经过优化sasl认证的随机数生成算法为用户态算法后，CPU sy% 100%的问题得以解决，同时代理性能在短连接场景下有了数倍/数十倍的性能提高。

3.问题总结及疑问解答
从上面的分析能够看出，该故障由多种因素连环触发引发，包括客户端配置使用不当、mongodb服务端内核极端状况异常缺陷、监控不全等。总结以下：
1.客户端配置不统一，同一个集群多个业务接口配置千奇百怪，超时配置、连接配置各不相同，增长了抓包排查故障的难度，超时时间设置过小容易引发反复重连。
2.客户端须要配全全部mongos代理，这样当一个代理故障的时候，客户端SDK默认会剔除该故障代理节点，从而能够保证业务影响最小，就不会存在单点问题。
3.同一集群多个业务接口应该使用同一配置中心统一配置，避免配置不统一。
4.Mongodb内核的新链接随机算法存在严重缺陷，在极端状况下引发严重性能抖动，甚至业务“雪崩”。

分析到这里，咱们能够回答第1章节的6个疑问点了，以下：

为何突发流量业务会抖动？
答：因为业务是java业务，采用连接池方式连接mongos代理，当有突发流量的时候，连接池会增长连接数来提高访问mongodb的性能，这时候客户端就会新增连接，因为客户端众多，形成可能瞬间会有大量新链接和mongos建链。连接创建成功后开始作sasl认证，因为认证的第一步须要生成随机数，就须要访问操做系统"/dev/urandom"文件。又由于mongos代理模型是默认一个连接一个线程，因此会形成瞬间多个线程访问该文件，进而引发内核态sy%负载太高。

为什么mongos代理引发“雪崩”，流量为什么跌零不可用？
答：缘由客户端某一时刻可能由于流量忽然有增长，连接池中连接数不够用，因而增长和mongos代理的连接，因为是老集群，代理仍是默认的一个连接一个线程模型，这样瞬间就会有大量连接，每一个连接创建成功后，就开始sasl认证，认证的第一步服务端须要产生随机数，mongos服务端经过读取"/dev/urandom"获取随机数，因为多个线程同时读取该文件触发内核态spinlock锁CPU sy% 100%问题。因为sy%系统负载太高，因为客户端超时时间设置太小，进一步引发客户端访问超时，超时后重连，重连后又进入sasl认证，又加重了读取"/dev/urandom"文件，如此反复循环持续。
此外，第一次业务抖动后，服务端扩容了8个mongos代理，可是客户端没有修改，形成B机房业务配置的2个代理在同一台服务器，没法利用mongo java sdk的自动剔除负载高节点这一策略，因此最终形成”雪崩”

为何数据节点没有任何慢日志，可是代理负载却CPU sy% 100%？
答：因为客户端java程序直接访问的是mongos代理，因此大量连接只发生在客户端和mongos之间，同时因为客户端超时时间设置过短(有接口设置位几十ms，有的接口设置位一百多ms，有的接口设置位500ms)，就形成在流量峰值的时候引发连锁反应(突发流量系统负载高引发客户端快速超时，超时后快速重连，进一步引发超时，无限死循环)。Mongos和mongod之间也是连接池模型，可是mongos做为客户端访问mongod存储节点的超时很长，默认都是秒级别，因此不会引发反复超时建链断链。

为什么A机房代理抖动的时候，A机房业务切到B机房后，仍是抖动？
答：当A机房业务抖动，业务切换到B机房的时候，客户端须要从新和服务端创建连接认证，又会触发大量反复建链断链和读取随机数"/dev/urandom"的流程，因此最终形成机房多活失败。

为什么异常时候抓包分析，客户端频繁建链断链，而且同一个连接建链到断链间隔很短？
答：频繁建链断链的根本缘由是系统sy%负载高，客户端极短期内创建连接后又端口的缘由是客户端配置超时时间过短。

理论上代理就是七层转发，消耗资源更少，相比mongod存储应该更快，为什么mongod存储节点无任何抖动，mongos代理却有严重抖动？
答：因为采用分片架构，全部mongod存储节点前面都有一层mongos代理，mongos代理做为mongod存储节点的客户端，超时时间默认秒级，不会出现超时现象，也就不会出现频繁的建链断链过程。

若是mongodb集群采用普通复制集模式，客户端频繁建链断链是否可能引发mongod存储节点一样的”雪崩”？
答：会。若是客户端过多，操做系统内核版本太低，同时超时时间配置过段，直接访问复制集的mongod存储节点，因为客户端和存储节点的认证过程和与mongos代理的认证过程同样，因此仍是会触发引发频繁读取"/dev/urandom"文件，引发CPU sy%负载太高，极端状况下引发雪崩。

4.“雪崩”解决办法
从上面的一系列分析，问题在于客户端配置不合理，加上mongodb内核认证过程读取随机数在极端状况下存在缺陷，最终形成雪崩。若是没有mongodb内核研发能力，能够经过规范化客户端配置来避免该问题。固然，若是客户端配置规范化，同时mongodb内核层面解决极端状况下的随机数读取问题，这样问题能够获得完全解决。
4.1 JAVA SDK客户端配置规范化
在业务接口不少，客户端机器不少的业务场景，客户端配置必定要作到以下几点：
1.超时时间设置为秒级，避免超时时间设置过端引发反复的建链断链。
2.客户端须要配置全部mongos代理地址，不能配置单点，不然流量到一个mongos很容易引发瞬间流量峰值的建链认证。
3.增长mongos代理数量，这样能够分流，保证同一时刻每一个代理的新键连接尽量的少，客户端在多代理配置时，默认是均衡流量分发的，若是某个代理负载高，客户端会自动剔除。
若是没有mongodb内核源码研发能力，能够参考该客户端配置方法，同时淘汰linux-2.6版本内核，采用linux-3.10或者更高版本内核，基本上能够规避踩一样类型的坑。
4.2 mongodb内核源码优化(摈弃内核态获取随机数，选择用户态随机数算法)
详见2.5.2 章节。

4.3 PHP短连接业务，如何规避踩坑
因为PHP业务属于短连接业务，若是流量很高，不可避免的要频繁建链断链，也就会走sasl认证流程，最终多线程频繁读取"/dev/urandom"文件，很容易引发前面的问题。这种状况，能够采用4.1 java客户端相似的规范，同时不要使用低版本的Linux内核，采用3.x以上内核版本，就能够规避该问题的存在。

Mongodb内核源码设计与实现分析
本文相关的Mongodb线程模型及随机数算法实现相关源码分析以下：
https://github.com/y123456yz/reading-and-annotate-mongodb-3.6