最近的副本集读取首选项仍然很慢

Question

注意：我也有posted this to dba.stackexchange.com。我不确定这个问题属于哪里。如果不在这里，告诉我，我会删除它。

我正在测试我的副本集，尤其是读取首选项，即使使用最近的读取首选项集，我的读取速度仍然很慢。

出于这个问题的目的，我们可以假设有 2 个 mongodb 实例（实际上有 3 个）。 PRIMARY 在阿姆斯特丹 (AMS)。 SECONDARY 在新加坡 (SG)。

我在运行测试脚本（节点+猫鼬）的这 2 个位置也有 2 个应用程序服务器。

1. 如果我运行 AMS 应用程序服务器（PRIMARY 的延迟非常低）， 简单的查找查询，我会在一秒钟内得到回复。
2. 但是，如果我从我在 SG 的应用服务器运行相同的查询，我会得到大约 4-7 秒的响应时间。
3. 如果我只是从 SG 应用服务器连接到 SG SECONDARY，我的查询时间会下降到

回到标准的代表集设置（最近的），如果我查看日志，我注意到如果我使用“最近”向 SG 发送查询，我可以在那里看到查询，但是我还在 PRIMARY 日志中看到了相同查询的条目（但行更少）。但有趣的是，即使在查询 SECONDARY 时，PRIMARY 日志中也始终存在一个条目。我不确定这是否有某种关系。

所以，如果我直接连接到最近的机器，我会得到一个 4s。

那么我的问题是，为什么？我是否错误地设置了我的副本服务器。这是客户端的问题（mongoose/mongodb），还是它实际上是按原意工作的，我误解了它在后台是如何工作的？

这是我的文件（为文字墙道歉）：

test.js

mongoose.connect(configDB.url); 
var start = new Date().getTime();
Model.find({})
.exec(function(err, betas){
    var end = new Date().getTime();
    var time = end - start;
    console.log(time/1000);
    console.log('finished');
    console.log(betas.length);
});

config，也尝试了 server 和 replSet 选项

module.exports = {
     'url' : 'user:pwd@ip-primary/db,user:pwd@ip-secondary/db,user:pwd@ip-secondary/db'
}

Beta 模型

var betaSchema = mongoose.Schema({
    .. some fields
}, { read: 'n' });

以及从 SG 应用服务器执行上述读取查询的日志输出：

初级日志：

2015-09-16T07:49:23.120-0400 D COMMAND  [conn12520] run command db.$cmd { listIndexes: "betas", cursor: {} }
2015-09-16T07:49:23.120-0400 I COMMAND  [conn12520] command db.$cmd command: listIndexes { listIndexes: "betas", cursor: {} } keyUpdates:0 writeConflicts:0 numYields:0 reslen:296 locks:{ Global: { acquireC
ount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } 0ms

中学日志

    2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Running query:
ns=db.betas limit=1000 skip=0
Tree: $and
Sort: {}
Proj: {}
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] Running query: query: {} sort: {} projection: {} skip: 0 limit: 1000
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Beginning planning...
=============================
Options = INDEX_INTERSECTION KEEP_MUTATIONS
Canonical query:
ns=db.betas limit=1000 skip=0
Tree: $and
Sort: {}
Proj: {}
=============================
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Index 0 is kp: { _id: 1 } io: { v: 1, key: { _id: 1 }, name: "_id_", ns: "db.betas" }
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Index 1 is kp: { email: 1 } io: { v: 1, unique: true, key: { email: 1 }, name: "email_1", ns: "db.betas", background: true, safe: null }
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Rated tree:
$and
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Planner: outputted 0 indexed solutions.
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Planner: outputting a collscan:
COLLSCAN
---ns = db.betas
---filter = $and
---fetched = 1
---sortedByDiskLoc = 0
---getSort = []
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] Only one plan is available; it will be run but will not be cached. query: {} sort: {} projection: {} skip: 0 limit: 1000, planSummary: COLLSCAN
2015-09-16T07:49:19.368-0400 D QUERY    [conn11831] [QLOG] Not caching executor but returning 109 results.
2015-09-16T07:49:19.368-0400 I QUERY    [conn11831] query db.betas planSummary: COLLSCAN ntoreturn:1000 ntoskip:0 nscanned:0 nscannedObjects:109 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:109 resl
en:17481 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } 0ms

Answer 1

输出中的信息表明数据库服务器正在快速处理查询。所以这个问题很可能出在数据库本身之外，可能在客户端。

您是否多次运行同一个查询并为每次执行计时？

我怀疑这可能是由于您的 MongoDB 客户端的一些初步发现 - 如果它最初没有命中每个节点并为响应计时，如何在响应之前知道最近的是什么？