首页 > 数据库> 文章详细

MongoDB通过profile监控慢日志

2021-04-28 15:54:24 阅读：263 来源： 互联网

标签：profile name ObjectId MongoDB handong system 日志 id

基础环境

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

本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享；
2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关；
3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关；
4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除；
5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。

ICode9

MongoDB通过profile监控慢日志

基础环境

开启profile

单机版

副本集

分片集

测试profile

输出解读