排查MongoDB CPU使用率高的问题

一、分析MongoDB数据库正在执行的请求

执行db.currentOp()命令，查看数据库当前正在执行的操作。命令的输出示例如下：

{
        "desc" : "conn632530",
        "threadId" : "140298196924160",
        "connectionId" : 632530,
        "client" : "11.192.159.236:57052",
        "active" : true,
        "opid" : 1008837885,
        "secs_running" : 0,
        "microsecs_running" : NumberLong(70),
        "op" : "update",
        "ns" : "mygame.players",
        "query" : {
            "uid" : NumberLong(31577677)
        },
        "numYields" : 0,
        "locks" : {
            "Global" : "w",
            "Database" : "w",
            "Collection" : "w"
        },
        ....

需要重点关注以下几个字段

备注：db.currentOp文档请参见此连接。

通过db.currentOp()查看正在执行的操作，分析是否有不正常耗时的请求正在执行。例如您的业务平时CPU使用率不高，运维管理人员连到MongoDB数据库执行了一些需要全表扫描的操作导致CPU使用率非常高，业务响应缓慢，此时需要重点关注执行时间非常耗时的操作。

二、分析MongoDB数据库的慢请求

1、通过use <database>命令进入指定数据库。

use mongodbtest

2、执行如下命令，查看该数据下的慢请求日志。

db.system.profile.find().pretty()

3、分析慢请求日志，查找引起MongoDB CPU使用率升高的原因。
以下为某个慢请求日志示例，可查看到该请求进行了全表扫描，扫描了11000000个文档，没有通过索引进行查询。

{
        "op" : "query",
        "ns" : "123.testCollection",
        "command" : {
                "find" : "testCollection",
                "filter" : {
                        "name" : "zhangsan"
                },
                "$db" : "123"
        },
        "keysExamined" : 0,
        "docsExamined" : 11000000,
        "cursorExhausted" : true,
        "numYield" : 85977,
        "nreturned" : 0,
        "locks" : {
                "Global" : {
                        "acquireCount" : {
                                "r" : NumberLong(85978)
                        }
                },
                "Database" : {
                        "acquireCount" : {
                                "r" : NumberLong(85978)
                        }
                },
                "Collection" : {
                        "acquireCount" : {
                                "r" : NumberLong(85978)
                        }
                }
        },
        "responseLength" : 232,
        "protocol" : "op_command",
        "millis" : 19428,
        "planSummary" : "COLLSCAN",
        "execStats" : {
                "stage" : "COLLSCAN",
                "filter" : {
                        "name" : {
                                "$eq" : "zhangsan"
                        }
                },
                "nReturned" : 0,
                "executionTimeMillisEstimate" : 18233,
                "works" : 11000002,
                "advanced" : 0,
                "needTime" : 11000001,
                "needYield" : 0,
                "saveState" : 85977,
                "restoreState" : 85977,
                "isEOF" : 1,
                "invalidates" : 0,
                "direction" : "forward",
....in"
                }
        ],
        "user" : "root@admin"
}

通常在慢请求日志中，您需要重点关注以下几点。

• 全表扫描（关键字： COLLSCAN、 docsExamined ）
  ①全集合（表）扫描COLLSCAN 。
      当一个操作请求（如查询、更新、删除等）需要全表扫描时，将非常占用CPU资源。在查看慢请求日志时发现COLLSCAN关键字，很可能是这些查询占用了CPU资源。
  ②通过查看docsExamined的值，可以查看到一个查询扫描了多少文档。该值越大，请求所占用的CPU开销越大。
  备注： 如果这种请求比较频繁，建议对查询的字段建立索引的方式来优化。
• 不合理的索引（关键字： IXSCAN、keysExamined ）
      通过查看keysExamined字段，可以查看到一个使用了索引的查询，扫描了多少条索引。该值越大，CPU开销越大。
      如果索引建立的不太合理，或者是匹配的结果很多。这样即使使用索引，请求开销也不会优化很多，执行的速度也会很慢。
      如下所示，假设某个集合的数据，x字段取值的重复率很高（假设只有1、2），而y字段取值的重复率很低。

{ x: 1, y: 1 }
{ x: 1, y: 2 }
{ x: 1, y: 3 }
......
{ x: 1, y: 100000} 
{ x: 2, y: 1 }
{ x: 2, y: 2 }
{ x: 2, y: 3 }
......
{ x: 1, y: 100000}

要实现 {x: 1, y: 2} 这样的查询

db.createIndex( {x: 1} )         效果不好，因为x相同取值太多
db.createIndex( {x: 1, y: 1} )   效果不好，因为x相同取值太多
db.createIndex( {y: 1 } )        效果好，因为y相同取值很少
db.createIndex( {y: 1, x: 1 } )  效果好，因为y相同取值少

关于{y: 1} 与 {y: 1, x: 1} 的区别，可参见MongoDB索引原理及复合索引官方文档。

• 大量数据排序（关键字： SORT、hasSortStage ）
  当查询请求里包含排序的时候， system.profile 集合里的hasSortStage字段会为 true 。如果排序无法通过索引满足，MongoDB会在查询结果中进行排序。而排序这个动作将非常消耗CPU资源，这种情况需要对经常排序的字段建立索引的方式进行优化。