MongoDB慢日志查询

MongoDB system.profile

前言

Part1:写在最前

    说到MongoDB的慢日志分析，就不得不提到profile分析器，profile分析器将记录的慢日志写到system.profile集合下，这个集合是一个固定集合。我们可以通过对这个集合的查询，来了解当前的慢日志，进而对数据库进行优化。

Part2:整体环境

MongoDB 3.2.5

实战

Part1:输出示范

在查询system.profile的时候，我们能够观察到所有的操作，包括remove,update,find等等都会被记录到system.profile集合中，该集合中包含了诸多信息，如：

{    "op" : "query",    "ns" : "test.c",    "query" : {       "find" : "c",       "filter" : {          "a" : 1       }    },    "keysExamined" : 2,    "docsExamined" : 2,    "cursorExhausted" : true,    "keyUpdates" : 0,    "writeConflicts" : 0,    "numYield" : 0,    "locks" : {       "Global" : {          "acquireCount" : {             "r" : NumberLong(2)          }       },       "Database" : {          "acquireCount" : {             "r" : NumberLong(1)          }       },       "Collection" : {          "acquireCount" : {             "r" : NumberLong(1)          }       }    },    "nreturned" : 2,    "responseLength" : 108,    "millis" : 0,    "execStats" : {       "stage" : "FETCH",       "nReturned" : 2,       "executionTimeMillisEstimate" : 0,       "works" : 3,       "advanced" : 2,       "needTime" : 0,       "needYield" : 0,       "saveState" : 0,       "restoreState" : 0,       "isEOF" : 1,       "invalidates" : 0,       "docsExamined" : 2,       "alreadyHasObj" : 0,       "inputStage" : {          "stage" : "IXSCAN",          "nReturned" : 2,          "executionTimeMillisEstimate" : 0,          "works" : 3,          "advanced" : 2,          "needTime" : 0,          "needYield" : 0,          "saveState" : 0,          "restoreState" : 0,          "isEOF" : 1,          "invalidates" : 0,          "keyPattern" : {             "a" : 1          },          "indexName" : "a_1",          "isMultiKey" : false,          "isUnique" : false,          "isSparse" : false,          "isPartial" : false,          "indexVersion" : 1,          "direction" : "forward",          "indexBounds" : {             "a" : [                "[1.0, 1.0]"             ]          },          "keysExamined" : 2,          "dupsTested" : 0,          "dupsDropped" : 0,          "seenInvalidated" : 0       }    },    "ts" : ISODate("2015-09-03T15:26:14.948Z"),    "client" : "127.0.0.1",    "allUsers" : [ ],    "user" : ""}

Part2:输出解读

system.profile.op

这一项主要包含如下几类

• insert

• query

• update

• remove

• getmore

• command

代表了该慢日志的种类是什么，是查询、插入、更新、删除还是其他。

system.profile.ns

该项表明该慢日志是哪个库下的哪个集合所对应的慢日志。

system.profile.query

该项详细输出了慢日志的具体语句和行为

system.profile.keysExamined

该项表明为了找出最终结果MongoDB搜索了多少个key

system.profile.docsExamined

该项表明为了找出最终结果MongoDB搜索了多少个文档

system.profile.keyUpdates

该项表名有多少个index key在该操作中被更改，更改索引键也会有少量的性能消耗，因为数据库不单单要删除旧Key，还要插入新的Key到B-Tree索引中

system.profile.writeConflicts

写冲突发生的数量，例如update一个正在被别的update操作的文档

system.profile.numYield

为了让别的操作完成而屈服的次数，一般发生在需要访问的数据尚未被完全读取到内存中，MongoDB会优先完成在内存中的操作

system.profile.locks

在操作中产生的锁，锁的种类有多种，如下：

Global	Represents global lock.
MMAPV1Journal	Represents MMAPv1 storage engine specific lock to synchronize journal writes; for non-MMAPv1 storage engines, the mode forMMAPV1Journal is empty.
Database	Represents database lock.
Collection	Represents collection lock.
Metadata	Represents metadata lock.
oplog	Represents lock on the oplog.

锁的模式也有多种，如下：

Lock Mode	Description
R	Represents Shared (S) lock.
W	Represents Exclusive (X) lock.
r	Represents Intent Shared (IS) lock.
w	Represents Intent Exclusive (IX) lock.

system.profile.locks.acquireCoun

在各种不用的种类下，请求锁的次数

system.profile.nreturned

该操作最终返回文档的数量

system.profile.responseLength

结果返回的大小，单位为bytes，该值如果过大，则需考虑limit()等方式减少输出结果

system.profile.millis

该操作从开始到结束耗时多少，单位为毫秒

system.profile.execStats

包含了一些该操作的统计信息，只有query类型的才会显示

system.profile.execStats.stage

包含了该操作的详细信息，例如是否用到索引

system.profile.ts

该操作执行时的时间

system.profile.client

哪个客户端发起的该操作，并显示出该客户端的ip或hostname

system.profile.allUsers

哪个认证用户执行的该操作

system.profile.user

是否认证用户执行该操作，如认证后使用其他用户操作，该项为空

——总结——

system.profile集合是定位慢SQL的手段之一，了解每一个输出项的含义有助于我们更快的定位问题。由于笔者的水平有限，编写时间也很仓促，文中难免会出现一些错误或者不准确的地方，不妥之处恳请读者批评指正。