首页 > 数据库> > MongoDB通过profile监控慢日志

MongoDB通过profile监控慢日志

2021-04-28 15:54:24 作者：互联网

基础环境

CentOS 7.5
MongoDB 4.2分片集群

开启profile

单机版

> db.getProfilingLevel()
0

> use admin
switched to db admin
> db.setProfilingLevel(1,100)
{ "was" : 0, "slowms" : 100, "sampleRate" : 1, "ok" : 1 }
> db.getProfilingLevel()
1

0为不记录
1为记录慢查询，默认为100ms
2为全部记录
100为慢查询标准，单位毫秒

副本集

副本集中profile每个节点单独控制，所以需要在primary节点和secondary单独开启，开启方式同单机版。

分片集

分片集群需要在mongod节点打开，和副本集一样，需要在primary节点和secondary单独开启，开启方式同单机版。

测试profile

在mongos执行慢查询

mongos> db.test.find({id:{$lt:200,$gt:100}}).skip(10).sort({"id":1})
{ "_id" : ObjectId("608789c01bcca323a261fcee"), "id" : 111, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcef"), "id" : 112, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf0"), "id" : 113, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf1"), "id" : 114, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf2"), "id" : 115, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf3"), "id" : 116, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf4"), "id" : 117, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf5"), "id" : 118, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf6"), "id" : 119, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf7"), "id" : 120, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf8"), "id" : 121, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcf9"), "id" : 122, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcfa"), "id" : 123, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcfb"), "id" : 124, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcfc"), "id" : 125, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcfd"), "id" : 126, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcfe"), "id" : 127, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fcff"), "id" : 128, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fd00"), "id" : 129, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }
{ "_id" : ObjectId("608789c01bcca323a261fd01"), "id" : 130, "name" : "handong", "name1" : "handong", "name2" : "handong", "name3" : "handong" }

在mongod节点进行慢日志查看。

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

也可以使用如下命令查看最新10条慢日志。

db.system.profile.find().limit(10).sort({ts:-1}).pretty()

{
    "op" : "query",
    "ns" : "db3.test",
    "command" : {
        "find" : "test",
        "filter" : {
            "id" : {
                "$lt" : 200,
                "$gt" : 100
            }
        },
        "projection" : {
            "$sortKey" : {
                "$meta" : "sortKey"
            }
        },
        "sort" : {
            "id" : 1
        },
        "runtimeConstants" : {
            "localNow" : ISODate("2021-04-28T06:45:59.790Z"),
            "clusterTime" : Timestamp(1619592355, 1)
        },
        "shardVersion" : [
            Timestamp(0, 0),
            ObjectId("000000000000000000000000")
        ],
        "lsid" : {
            "id" : UUID("45045602-80dc-43b5-ab07-957b4aa2d094"),
            "uid" : BinData(0,"O0CMtIVItQN4IsEOsJdrPL8s7jv5xwh5a/A5Qfvs2A8=")
        },
        "$clusterTime" : {
            "clusterTime" : Timestamp(1619592355, 1),
            "signature" : {
                "hash" : BinData(0,"hsabhJcUvXSZ+19pG120EZLGAm8="),
                "keyId" : NumberLong("6941260985399246879")
            }
        },
        "$audit" : {
            "$impersonatedUsers" : [
                {
                    "user" : "admin",
                    "db" : "admin"
                }
            ],
            "$impersonatedRoles" : [
                {
                    "role" : "root",
                    "db" : "admin"
                }
            ]
        },
        "$client" : {
            "application" : {
                "name" : "MongoDB Shell"
            },
            "driver" : {
                "name" : "MongoDB Internal Client",
                "version" : "4.2.12"
            },
            "os" : {
                "type" : "Linux",
                "name" : "CentOS Linux release 7.9.2009 (Core)",
                "architecture" : "x86_64",
                "version" : "Kernel 3.10.0-1160.24.1.el7.x86_64"
            },
            "mongos" : {
                "host" : "mongo6:30000",
                "client" : "127.0.0.1:48674",
                "version" : "4.2.12"
            }
        },
        "$configServerState" : {
            "opTime" : {
                "ts" : Timestamp(1619592355, 1),
                "t" : NumberLong(22)
            }
        },
        "$db" : "db3"
    },
    "keysExamined" : 0,
    "docsExamined" : 1000000,
    "hasSortStage" : true,
    "cursorExhausted" : true,
    "numYield" : 7813,
    "nreturned" : 99,
    "queryHash" : "39C3AA47",
    "planCacheKey" : "39C3AA47",
    "locks" : {
        "ParallelBatchWriterMode" : {
            "acquireCount" : {
                "r" : NumberLong(1)
            }
        },
        "ReplicationStateTransition" : {
            "acquireCount" : {
                "w" : NumberLong(7815)
            }
        },
        "Global" : {
            "acquireCount" : {
                "r" : NumberLong(7815)
            }
        },
        "Database" : {
            "acquireCount" : {
                "r" : NumberLong(7814)
            }
        },
        "Collection" : {
            "acquireCount" : {
                "r" : NumberLong(7814)
            }
        },
        "Mutex" : {
            "acquireCount" : {
                "r" : NumberLong(2)
            }
        }
    },
    "flowControl" : {

    },
    "storage" : {

    },
    "responseLength" : 14044,
    "protocol" : "op_msg",
    "millis" : 918,
    "planSummary" : "COLLSCAN",
    "execStats" : {
        "stage" : "PROJECTION_DEFAULT",
        "nReturned" : 99,
        "executionTimeMillisEstimate" : 12,
        "works" : 1000103,
        "advanced" : 99,
        "needTime" : 1000003,
        "needYield" : 0,
        "saveState" : 7813,
        "restoreState" : 7813,
        "isEOF" : 1,
        "transformBy" : {
            "$sortKey" : {
                "$meta" : "sortKey"
            }
        },
        "inputStage" : {
            "stage" : "SORT",
            "nReturned" : 99,
            "executionTimeMillisEstimate" : 11,
            "works" : 1000103,
            "advanced" : 99,
            "needTime" : 1000003,
            "needYield" : 0,
            "saveState" : 7813,
            "restoreState" : 7813,
            "isEOF" : 1,
            "sortPattern" : {
                "id" : 1
            },
            "memUsage" : 11583,
            "memLimit" : 33554432,
            "inputStage" : {
                "stage" : "SORT_KEY_GENERATOR",
                "nReturned" : 99,
                "executionTimeMillisEstimate" : 11,
                "works" : 1000003,
                "advanced" : 99,
                "needTime" : 999903,
                "needYield" : 0,
                "saveState" : 7813,
                "restoreState" : 7813,
                "isEOF" : 1,
                "inputStage" : {
                    "stage" : "COLLSCAN",
                    "filter" : {
                        "$and" : [
                            {
                                "id" : {
                                    "$lt" : 200
                                }
                            },
                            {
                                "id" : {
                                    "$gt" : 100
                                }
                            }
                        ]
                    },
                    "nReturned" : 99,
                    "executionTimeMillisEstimate" : 10,
                    "works" : 1000002,
                    "advanced" : 99,
                    "needTime" : 999902,
                    "needYield" : 0,
                    "saveState" : 7813,
                    "restoreState" : 7813,
                    "isEOF" : 1,
                    "direction" : "forward",
                    "docsExamined" : 1000000
                }
            }
        }
    },
    "ts" : ISODate("2021-04-28T06:45:59.724Z"),
    "client" : "172.16.254.136",
    "appName" : "MongoDB Shell",
    "allUsers" : [
        {
            "user" : "__system",
            "db" : "local"
        }
    ],
    "user" : "__system@local"
}

输出解读

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 database lock.
Metadata	Represents database 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

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

标签：profile,name,ObjectId,MongoDB,handong,system,日志,id
来源： https://blog.51cto.com/u_12592884/2739677