背景介绍
- 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;
}
