为什么 MongoDB 可尾游标记录为慢？答案

【问题标题】：Why is MongoDB tailable cursor logged as slow?为什么 MongoDB 可尾游标记录为慢？
【发布时间】：2013-01-16 10:48:36
【问题描述】：

我正在使用可尾光标读取跟踪集合 (http://docs.mongodb.org/manual/tutorial/create-tailable-cursor)。这似乎工作正常，但我记录了以下慢查询：

Tue Jan 15 17:54:37 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2268ms
Tue Jan 15 17:54:38 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 nreturned:1 reslen:513 315ms
Tue Jan 15 17:54:39 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 nreturned:2 reslen:1800 962ms
Tue Jan 15 17:54:41 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2268ms
Tue Jan 15 17:54:43 [conn28] getmore trace.traces query: { time: { $gte: new Date(1358254406370) } } cursorid:7095190436798608732 reslen:20 2283ms

该行每隔几秒就会被记录一次，即使根本没有写入集合。

我使用的是 Mongo 2.0.8（和 Java 驱动程序 2.10.1）。我也在 Mongo 2.2.2 上尝试过，但这里没有记录（即使使用 --profile 2），但是，我仍然在 system.profile 集合中看到它。

有谁知道为什么这个查询（报告为）慢？

这是个人资料信息：

> db.system.profile.find().limit(1).sort( { millis : -1 } ).pretty()
{
    "ts" : ISODate("2013-01-15T17:33:48.354Z"),
    "op" : "getmore",
    "ns" : "trace.traces",
    "query" : {
            "time" : {
                    "$gte" : ISODate("2013-01-15T12:56:57.589Z")
            }
    },
    "cursorid" : NumberLong("8205177764687670896"),
    "ntoreturn" : 0,
    "keyUpdates" : 0,
    "numYield" : 0,
    "lockStats" : {
            "timeLockedMicros" : {
                    "r" : NumberLong(30492),
                    "w" : NumberLong(0)
            },
            "timeAcquiringMicros" : {
                    "r" : NumberLong(22499),
                    "w" : NumberLong(3)
            }
    },
    "nreturned" : 0,
    "responseLength" : 20,
    "millis" : 2356,
    "client" : "127.0.0.1",
    "user" : ""
}

这里是集合的统计数据：

> db.traces.stats()
{
    "ns" : "trace.traces",
    "count" : 41897,
    "size" : 51760464,
    "avgObjSize" : 1235.4217247058261,
    "storageSize" : 52432896,
    "numExtents" : 1,
    "nindexes" : 1,
    "lastExtentSize" : 52432896,
    "paddingFactor" : 1,
    "systemFlags" : 1,
    "userFlags" : 0,
    "totalIndexSize" : 1422624,
    "indexSizes" : {
            "_id_" : 1422624
    },
    "capped" : true,
    "max" : 2147483647,
    "ok" : 1
}

【问题讨论】：

标签： mongodb

【解决方案1】：

我认为当没有可用文档时，您的光标会阻止等待新文档。看到慢查询都有reslen:20。这在我看来是正常行为。

【讨论】：

我确实想到了这个想法。遗憾的是，它总是把我的日志和个人资料数据弄得一团糟。