一次MongoDB故障的复盘

  • 时间:
  • 浏览:0

背景(简单介绍背景情况汇报)

主从克隆技术延迟是另4个非常严重且影响业务的指标,此处显示的5s的时间在有读写分离的场景中不可能 都时要认为是非常影响业务的。

临时应对与考量

验证与总结

而代码中游标加入了这一属性

撤出 SecondaryPreferred,以保证调用接口正常

类型为getmore

接下来尝试分析为社 突然出现主从延迟,从就让 梳理的集群情况汇报来看,除去主从延迟和local.oplog.rs的slow query,某些指标均十分健康(并前会)。

不过这反而致使整个排查过程变得更加有分享和借鉴价值。在这里分享给朋友 希望都时要让朋友 补救踩坑。

当时某些我感觉到该服务使用游标的办法趋于稳定不妥,还未能删改与难题报告 关联起来,记得上文中提到当时的整体常用监控指标都十分“健康”(这里埋下了另4个伏笔),此时从客户处有获知了曾经监控指标–cursor数,客户告知当时主节点cursor总数为73000k+个。

都时要看后上述慢查询有有几个特点:

方案2时要客户包装上层业务进行修改,而客户的接口调用场景极多,故而放弃。(实在放弃该方案,而且时要提醒的是,在任何涉及到数据一致性要求的业务场景都时要充分考虑到异常和不可能 性,在业务层尽不可能 的规避。这也是为哪此有主从延迟的就让 Teambition系统某种并未)

根据迟来的监控指标确认cursor的异常并分析

难题报告 为在第二步的过程中,无法查找到第一步中”新建的任务_id”。考虑到该客户使用的是MongoDB克隆技术集架构,而且第还还有一个接口的query使用了SecondaryPreferred,不可能 此时朋友 无法连接到数据库查看指标也无法查看后客户处该mongodb集群的监控信息,根据已有信息初步判断故障原因分析不可能 为“主从延迟”原因分析的数据一致性难题报告 。

梳理后总结为:

接下来朋友 将目光聚焦到了local.oplog.rs的慢查询上。

回归到此次故障的场景,实在db.printSlaveReplicationInfo()趋于稳定不准确的不可能 ,而且以当时的pqs情况汇报来判断,应该是真实突然出现了主从延迟。

此时朋友 正好在1ms后于primary节点中执行了db.printSlaveReplicationInfo()

验证2:在tailable,awaitData和noCursorTimeout定义下,服务异常重启会原因分析cursor不被释放,进而造成cursor堆积。

集群节点间网络延迟(客户网络工程师反馈节点间网络正常,该不可能 排除)

不可能 该集群环境的监控以及情况汇报无法直接查看不让 通过客户转述,这一过程遗漏了某些信息也造成了某些时间的浪费,在有不可能 的情况汇报下,mongodb的使用者还是时要对mongodb的全面指标进行监控,魔鬼往往隐藏在细节中。

调用接口B(可简单认为insert了第一根数据b,但在insert就让 检查了接口A返回的数据a的_id)

在mongodb源码中定义了曾经的计算办法

同步业务代码在建立cursor时,使用了tailable,awaitData,且noCursorTimeout的定义,致使cursor在业务这么主动close的情况汇报下,将永久趋于稳定。(而且此时cursor监听在primary节点中,后续朋友 新增了hidden member用于该业务的请求)。

cursor的堆积造成了异常的内存消耗(wt cache外的内存),进而影响到了从节点producer thread的速率单位单位,从而原因分析了主从延迟的产生。

朋友 都时要看后,基准时间是primary节点的optimeDate(将其定义为startOptimeDate),各个从节点的延迟是按照startOptimeDate – st(也某些我各个从节点的optimeDate)进行计算(不包括arbiter)。

不可能 短时间内朋友 无法查看客户处mongodb集群的情况汇报与监控指标,方案3实现周期长于前两者,故而放弃。

流量稳定无暴增

Cache Activitiy稳定无暴增

让朋友 来梳理下这次故障的前因后果。

Resident Memory稳定,且整体eviction情况汇报良好

在初步获取到了结论后,朋友 就让 刚现在开始进行相应的验证。

不可能 该服务采用pm2进行服务运价值形式管理,朋友 不断向其发送异常关闭的signal,pm2在其error后不断重启。期间观察db.serverStatus().metrics.cursor情况汇报,发现db.serverStatus().metrics.cursor.open.noTimeout值持续上升堆积。确认了cursor堆积的原因分析。

趋于稳定local.oplog.rs的slow query

此前该业务突然出现过异常,从而原因分析服务不断异常与重启,每种了73000k+个notimeout的cursor,而每个cursor是有额外内存的消耗,从而原因分析主节点内存被无效的cursor占用(此处占用的内存前会wt cache,某些我剩余的ram,某些此时监控的wt cache的相关指标前会正常的),而且每个请求除了利用wt cache外还是会产生內部ram的消耗,如connection,结果集临时存储等。此时从节点producer thread来拉取oplog的速率单位单位降低,进一步造成了主从延迟的产生。

QPS趋于稳定低位运行,且业务场景读远大与写

主要的慢查询主要的条件为如下,大多为getmore。

集群正趋于稳定写操作极为空闲的阶段

在此,朋友 对故障的排查进行一次复盘。

主从延迟不稳定,有时飙升至5s

调用接口A(可简单认为insert了第一根数据a)

主从延迟分析与排查,并通过每种mongo源码佐证推断

而上层业务将A、B另4个接口的调用包装后的场景不可能 SecondaryPreferred的原因分析,原因分析B接口异常,最终影响了业务的正常对外服务。

一般主从延迟有以下几种不可能 原因分析:

看起来从节点落后了主节点25秒的时间,十分严重。而且不可能 场景的特殊性,此时落后的是另4个写操作,而且不可能 执行时间的原因分析,该写操作后续变快也完成了同步。此时的25secs对于集群来说影响甚微。

背景

db.printSlaveReplicationInfo()所体现的主从延迟暂且一定真的代表延迟,而且该监控指标任何就让 都时要提起120%的关注度。

通过慢查询定位异常业务

补救对local库内表的操作,不可能 有骚操作的需求,时要明白当时人在做哪此,一块儿将骚操作安排在隐藏节点中进行(不可能 此次最初朋友 的业务使用的是隐藏节点,该难题报告 就不让直接影响到业务)且新版本都时要使用changestream来满足类事trace oplog的需求。

9月初朋友 的某客户反馈,部署在其私有云中的Teambition系统趋于稳定异常。该客户通过调用系统的开放API包装了一层业务向內部提供,此时另4个连续接口调用之间突然出现了数据一致性异常,原因分析包装的上层业务无法正常使用,而此时Teambition系统某种业务使用均正常。

接到反馈后朋友 与对方同步了其包装的业务逻辑,大体为:

当时涉及到了主从延迟,慢查询,cursor的不当使用等mongodb难题报告 ,本文将从这有几个方面全面复盘整个故障的排查过程,其含有有了如下内容:

在朋友 将SecondaryPreferred的配置撤出 后,上层业务恢复了正常。朋友 也辗转获得了客户处mongodb集群的每种监控信息、情况汇报等。

至此,朋友 大体推断出了根因。

此时primary的optimeDate为ISODate(“2018-10-24T07:00:300Z”),而不可能 朋友 执行该命令的就让 各个从节点完成同步,某些各个从节点的optimeDate为ISODate(“2018-10-24T07:00:05Z”)。于是乎朋友 得到了曾经的返回

看起来该值的计算并这么哪此难题报告 ,而且在某类场景下,db.printSlaveReplicationInfo()的返回值(即主从延迟)并这么这么贴切。如:

从里面的特点朋友 都时要判断类事搞笑的话不让是正常业务场景,也前会A或B接口触发的,回顾下整个服务体系中会对oplog.rs有这么查询的为trace oplog的场景,来源于另4个从mongodb同步数据到elasticsearch的应用。该应用会实时trace oplog 并进行同步。检查了下服务代码,每种如下:

从节点的磁盘性能过高 (客户在当时并未提供io和吞吐情况汇报,不过按照当时的低位qps,不应当会有磁盘性能难题报告 ,暂时排除)

在ISODate(“2018-10-24T07:00:05Z”)进行了另4个写操作a(insert/update/delete)

而后在ISODate(“2018-10-24T07:00:300Z”)才进行了下另4个写操作b

同步服务中不当的使用了noCursorTimeout的cursor。

朋友 知道oplog是这么严格意义上的索引,某些类事游标在第一次建立的就让 会比较耗时,持续trace到最后的末尾的就让 会趋于稳定tailabled和awaitData情况汇报,此时实时trace数据的getmore就应该趋于稳定相对稳定的快速情况汇报。

深究与排查

首先从最直观的难题报告 进行入手,观察到 db.printSlaveReplicationInfo()返回的结果和客户处集群的可视化监控显示主从延迟不稳定,会不时飙升至5s,如:

Connections连接数稳定,并无暴增暴减

slow query内getmore趋于稳定这一属性。

合理利用读写分离,MongoDB的读写分离并前会真正意义上的将读写压力删改分离,时要明确业务对于数据一致性的需求,一致性要求强的场景补救SecondaryPreferred不可能 通过业务价值形式的调整补救该难题报告 。

该服务异常重启多次造成了primary中cursor的堆积。

不可能 该上层业务重要性较高,摆在肩头的首要情况汇报是恢复该业务的可用性,综合考虑后,得出了如下的几种补救办法:

主节点有几滴 并发写原因分析从节点无法及时追上(当时qps趋于稳定低位,replWriter为默认系统进程数,不应趋于稳定瓶颈,暂时排除)

在上述某种方案中,朋友 选用了方案1“撤出 SecondaryPreferred”来作为应急补救方案。原因分析如下:

临时应对与考量(该情况汇报下快速恢复业务的选用)

使用cursor就让 暂且使用noCursorTimeout能力,为cursor设置合理的timeout,由应用来控制timeout后的重试机制。以此来保证cursor的合理利用。

MongoDB的读写分离并前会真正意义上的将读写压力删改分离,Primary上的写最终还是以oplog的形式在从上进行了回放,读写分离的效果有限,某些在判断集群整体压力趋于稳定合理范围内,朋友 考虑撤出

是针对oplog.rs的慢查询

前段时间笔者的客户遇到了另4个主从延迟原因分析的业务故障,故障的原因分析曾经是较为简单易查的,而且不可能 客户环境的安全、保密性要求,监控和指标不让 间接获知,信息比较片段化与迟缓。

不过朋友 也时要额外注意,该值不为0暂且能3000%代表系统趋于稳定主从延迟难题报告 。朋友 先来看看db.printSlaveReplicationInfo()的结果是怎么还后能 获取的。

不调整接口B的逻辑,在上层调用接口A和B之间加一层保护,通过业务的手段补救在短时间内进行连续的调用,通过业务价值形式的微调拉长A与B接口调用之间的时间轴,如:先交由用户配置所需字段,在提交时再进行任务_id的判断与绑定

为了释放cursor朋友 将节点实例重启并关闭同步服务,持续观察后,确认主从延迟情况汇报不再突然出现恢复正常。将SecondaryPreferred重新启用,业务也一切正常。

主节点上趋于稳定某些异常的慢查询,影响了从节点上producer thread拉取oplog的速率单位单位,从而原因分析延迟(最有不可能 )

体现了若干游标定义

验证1:几滴 cursor原因分析wt cache外的ram资源紧张,进而造成主从延迟。

朋友 知道MongoDB的主从同步为异步同步,主从节点之间延迟在所难免,而且正常情况汇报下延迟时间大多为毫秒级别,大多不让影响到正常业务。此时的难题报告 透露着另4个信息,该MongoDB集群趋于稳定异常,而且不可能 第一时间无法获取集群情况汇报,具体的异常暂时无从得知。

而当时系统内几滴 的getmore成为了slow query,考虑到当时整体qps情况汇报,朋友 对slow query和代码进行仔细的查看。发现了端倪:

SecondaryPreferred,将接口B的请求发向Primary。

至此,这一难题报告 算不算删改落下帷幕,总结一下踩的坑以及怎么还后能 补救