MongoDB Secondary 延时高（同步锁）问题分析

背景介绍

• MongoDB 复制集里 Secondary 不断从主上批量拉取 oplog，然后在本地重放，以保证数据与 Primary 一致。同步原理参考MongoDB复制集同步原理解析

• Secondary 拉取到一批 oplog 后，在重放这批 oplog 时，会加一个特殊的 Lock::ParallelBatchWriterMode 的锁，这个锁会阻塞所有的读请求，直到这批 oplog 重放完成。这么做的原因有2个

  • 尽量避免脏读，等一批 oplog 重放完后，这批数据才允许用户读到。
  • 尽量保证同步性能，设想一下，如果重放 oplog 时，使用普通的锁，那么 oplog 的重放就需要跟正常的读写竞争锁资源，如果 Secondary 上有大量的读，那么势必会造成备同步逐步跟不上。参考 SERVER-18190

案例分析

基于上述问题，某些用户在读取备节点时，可能遇到因为 Secondary 重放 oplog 占用特殊锁时间较长，导致读取的延时变长。

问题1：单个请求耗时长

一个长达1小时的『前台创建索引』请求，在 Secondary 节点上重放时，一直占用 ParallelBatchWriterMode 锁，导致 Secondary 上所有请求阻塞长达1小时，这个案例我在Secondary节点为何阻塞请求近一个小时？ 里已经分析过，这里不再赘述，解决方案是尽量后台建索引。

上述场景除了会影响 Secondary 上的读请求，如果 Priamry 上写请求指定了 writeConcern 来写多个节点（{w: 2+}），而 Secondary 又一直阻塞在创建索引上，导致其后的oplog 重放都要等待创建索引结束，从而主上的写入也阻塞。

问题2：多个请求加起来耗时长

当主上写入并发很大时，Secondary 每次能拉到很多条 oplog，然后并发重放，重放一条的耗时可能很小，但累计起来一次重放上百、上千条 oplog，耗时就会高很多，而重放过程中，Secondary 上读请求都是要阻塞等待的，所以总体看上去，「Secondary 上平均延时，可能比 Primary 上更长点」（这就是为什么很多用户在写入比较多时，会发现读secondary 比 读praimry 更慢），但只要延时在可接受范围内，这个问题并无影响，而且根据云上用户使用的经验，绝大部分用户都是感受不到这个差异的。

但有一种情况值要注意

从上面的例子可以看到，一条 update 操作，指定了 {multi: true} 选项，更新了2个匹配的文档，针对每个文档都产生了一条 oplog（主要为了保证 oplog 幂等性），如果匹配的文档有成千上万条，就会产生对应数量的 oplog，然后 Secondary 拉取这些 oplog 并重放；这个场景下，update 的开销在Secondary 上被放大多倍，此时Secondary 的读延时可能会受比较大的影响。

如何评估重放 oplog 时锁的影响有多大？

从上述的例子可以看出，Secondary 在某些场景下会出现读延时很高的情况，那么当实际遇到问题时，如何判断问题就是 Secondary 重放 oplog 占用锁时间太长导致呢？

我们的做法是增加审计日志，把『Secondary 节点重放每一批 oplog 的时间开销记录到审计日志』里，这样就能很方便的看出影响到底有多大，如下是一个『简化版本的加日志的patch』，有需要的可以应用到 MongoDB 3.2上。

diff --git a/src/mongo/db/repl/sync_tail.cpp b/src/mongo/db/repl/sync_tail.cpp
index 50517c2..e7d58bc 100644
--- a/src/mongo/db/repl/sync_tail.cpp
+++ b/src/mongo/db/repl/sync_tail.cpp
@@ -550,6 +550,8 @@ OpTime SyncTail::multiApply(OperationContext* txn,
     // stop all readers until we're done
     Lock::ParallelBatchWriterMode pbwm(txn->lockState());

+    unsigned long long startTime = curTimeMicros64();
+
     if (inShutdownStrict()) {
         log() << "Cannot apply operations due to shutdown in progress";
         return OpTime();
@@ -585,6 +587,8 @@ OpTime SyncTail::multiApply(OperationContext* txn,
         setMinValid(txn, boundaries->end, DurableRequirement::None);  // Mark batch as complete.
     }

+    log() << "batch writer cost " << (curTimeMicros64() - startTime) << us;
+
     return lastOpTime;
 }

参考资料

• MongoDB复制集同步原理解析
• Secondary节点为何阻塞请求近一个小时？
• 阿里云数据库 MongoDB 版