4

谁能提供有关如何解决我在使用 mongo 时遇到的零星缓慢问题的见解,或者根据我的缓慢操作日志指出任何明显的问题?

我有 Mongo v3.2.6,使用安装在运行 ubuntu 服务器 14.04 的 m4.large(8GB Ram,2 个虚拟内核)ec2 实例上的 WiredTiger 引擎。在同一台服务器上安装了一个 java 进程,它使用许多线程从/向 mongo 进程读取/写入。没有副本集(我知道应该有),没有我可以看到的内存问题,但是,我一直在遇到无法诊断的零星慢查询。

以下是 2016 年 6 月 21 日的完整日志,其中显示了一些非常长的查询(10 多秒),查询通常在几毫秒内完成。

2016-06-21T01:27:44.806ZI COMMAND [conn156] 更新 company.token 查询:{ _id:“1111”} 更新:{ _id:“1111”,_class:“company.domain.Token”,userUUID:“5555 ", expires: 1466476050734 } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } },数据库:{ acquireCount : { w: 2 } },集合:{ acquireCount: { w: 2 } } } 14071ms
2016-06-21T01:27:44.806ZI COMMAND [conn151] 更新 company.token 查询:{ _id:“2222”} 更新:{ _id:“2222”,_class:“company.domain.Token”,userUUID:“6666 ", expires: 1466476050414 } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } },数据库:{ acquireCount : { w: 2 } },集合:{ acquireCount: { w: 2 } } } 14391ms
2016-06-21T01:27:44.811ZI COMMAND [conn150] insert company.count ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } },数据库:{acquireCount:{w:1}},集合:{acquireCount:{w:1}}}14074ms
2016-06-21T01:39:45.807ZI COMMAND [conn151] 更新 company.token 查询:{ _id:“3333”} 更新:{ _id:“3333”,_class:“company.domain.Token”,userUUID:“7777 ", expires: 1466476776277 } keysExamined:0 docsExamined:0 nMatched:1 nModified:1 upsert:1 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } },数据库:{acquireCount:{w:1}},集合:{acquireCount:{w:1}}} 9529ms
2016-06-21T10:34:14.596ZI 命令 [conn156] 命令 company.count 命令:聚合 { 聚合:“计数”,管道:[ { $match:{ lId:“4444”,$ 和:[ { iTS:{ $gte: 1466475578989 } }, { iTS: { $lte: 1466505254467 } } ] } }, { $group: { _id: { rId: "$rId", sType: "$sType" },计数:{ $sum: "$rVal" } } } ] } keyUpdates:0 writeConflicts:0 numYields:92 reslen:162 locks:{ Global: { acquireCount: { r: 190 } }, Database: { acquireCount: { r: 95 } }, Collection: { acquireCount: { r: 95 } } } 协议:op_query 113ms
2016-06-21T10:39:17.113ZI COMMAND [conn146] command company.count 命令:聚合 { 聚合:“计数”,管道:[ { $match:{ lId:“4444”,$ 和:[ { iTS:{ $gte: 1466475589300 } }, { iTS: { $lte: 1466505556971 } } ] } }, { $group: { _id: { rId: "$rId", sType: "$sType" },计数:{ $sum: "$rVal" } } } ] } keyUpdates:0 writeConflicts:0 numYields:93 reslen:162 locks:{ Global: { acquireCount: { r: 192 } }, Database: { acquireCount: { r: 96 } }, Collection: { acquireCount: { r: 96 } } } 协议:op_query 141ms
2016-06-21T10:41:16.871ZI 命令 [conn156] 命令 company.count 命令:聚合 { 聚合:“计数”,管道:[ { $match:{ lId:“4444”,$ 和:[ { iTS:{ $gte: 1466475578989 } }, { iTS: { $lte: 1466505676744 } } ] } }, { $group: { _id: { rId: "$rId", sType: "$sType" },计数:{ $sum: "$rVal" } } } ] } keyUpdates:0 writeConflicts:0 numYields:94 reslen:162 locks:{ Global: { acquireCount: { r: 194 } }, Database: { acquireCount: { r: 97 } }, Collection: { acquireCount: { r: 97 } } } 协议:op_query 110ms

缓慢的查询似乎总是updateinsert操作。上述慢查询表的一个集合是company.token,它有大约 55k 文档,平均大小为 160B。非常频繁地读取此集合(大约每 15 秒突发高达每秒 100 次)。读取查询使用主_id键进行搜索,因此它命中了主键索引。

日志中的另一个集合company.count包含约 270 万个文档,平均大小为 587B,并且写入非常频繁(每 15 秒每秒插入约 100 次突发)。该集合具有针对集合执行的稳定聚合读取查询(也显示在日志中),每分钟几十个。聚合读取match子句命中复合索引,并且扫描的文档似乎永远不会多于返回的文档(executionStats显示在底部)。插入查询往往完成得非常快,每次插入大约需要 1-4 毫秒,但是,每天一次或两次 mongo 似乎会占用 10 有时 20 秒才能完成其他快速操作。

我对延迟的最佳猜测是来自日志中两个集合的高并发写入和读取,但是,我的印象是 WiredTiger 在文档级别使用了意图排他锁和意图共享锁,这应该允许高并发。

最后一点是,我有时会看到另一个仅包含一个文档的集合需要 10 秒才能更新,因此看起来写入和读取队列可能在全局或数据库级别已达到极限。有什么方法可以确认吗?

{
  "executionStats":{
    "executionSuccess":true,
    "nReturned":12006,
    "executionTimeMillis":19,
    "totalKeysExamined":12006,
    "totalDocsExamined":12006,
    "executionStages":{
      "stage":"FETCH",
      "nReturned":12006,
      "executionTimeMillisEstimate":20,
      "works":12007,
      "advanced":12006,
      "needTime":0,
      "needYield":0,
      "saveState":93,
      "restoreState":93,
      "isEOF":1,
      "invalidates":0,
      "docsExamined":12006,
      "alreadyHasObj":0,
      "inputStage":{
        "stage":"IXSCAN",
        "nReturned":12006,
        "executionTimeMillisEstimate":0,
        "works":12007,
        "advanced":12006,
        "needTime":0,
        "needYield":0,
        "saveState":93,
        "restoreState":93,
        "isEOF":1,
        "invalidates":0,
        "keyPattern":{
          "lId":1,
          "iTS":1
        },
        "indexName":"lId_1_iTS_1",
        "isMultiKey":false,
        "isUnique":false,
        "isSparse":false,
        "isPartial":false,
        "indexVersion":1,
        "direction":"forward",
        "indexBounds":{
          "lId":[
            "[\"d4444\", \"4444\"]"
          ],
          "iTS":[
            "[1466475578989.0, 1466505676744.0]"
          ]
        },
        "keysExamined":12006,
        "dupsTested":0,
        "dupsDropped":0,
        "seenInvalidated":0
      }
    }
  }
}
4

0 回答 0