####################################
首先，慢查询日志是针对数据库级别的，咱们设置的时候，要先use 数据库，再开启，一定先确定某个数据库再db.setProfilingLevel(2,500)
# 获取超过0.5秒的慢查询：
db.system.profile.find({millis:{$gt:500}})
# 获取最新的慢查询：
db.system.profile.find().sort({$natural:-1})
一、获取慢查询配置：
性能分析器Profiling级别参数：
- 0值：关闭性能分析器，不收集任何数据。mongod总是将时间长于slowOpThresholdMs阀值的操作写入到日志。这是默认的性能分析器级别。
- 1值：只收集慢操作性能分析数据.默认慢操作是那些操作时间大于100毫米的操作。
- 2值：收集所有数据库操作的性能分析数据。
##############################################################
db.getProfilingStatus() db.setProfilingLevel(1,500)
db.setProfilingLevel(1,1000) # 相当于1s
db.setProfilingLevel(0) #关闭慢查询
db.system.profile.drop() # 删除慢查询集合
db.createCollection( "system.profile", { capped: true, size:10000000 } ) # 重建慢查询集合
db.setProfilingLevel(2,500) #开启慢查询和配置慢查询阈值
具体例子如下：
glc-test:PRIMARY> db.getProfilingStatus() { "was" : 0, "slowms" : 500, "ratelimit" : 1, "sampleRate" : 1, "operationTime" : Timestamp(1606295083, 1), "$clusterTime" : { "clusterTime" : Timestamp(1606295083, 1), "signature" : { "hash" : BinData(0,"21NKX80GE0q/yEV5AJII6XAwctQ="), "keyId" : NumberLong("6856584343653974019") } } } glc-test:PRIMARY> db.getProfilingLevel() 0 glc-test:PRIMARY> db.setProfilingLevel(1,500) { "was" : 0, "slowms" : 500, "ratelimit" : 1, "sampleRate" : 1, "ok" : 1, "operationTime" : Timestamp(1606295103, 1), "$clusterTime" : { "clusterTime" : Timestamp(1606295103, 1), "signature" : { "hash" : BinData(0,"9m9XwRHgd18Ik2AouRUIvh2DFLg="), "keyId" : NumberLong("6856584343653974019") } } } glc-test:PRIMARY>
二、删除慢查询集合：
db.setProfilingLevel(0) db.system.profile.drop()
具体例子如下：
glc-test:PRIMARY> db.getProfilingStatus() { "was" : 1, "slowms" : 500, "ratelimit" : 1, "sampleRate" : 1, "operationTime" : Timestamp(1606294533, 1), "$clusterTime" : { "clusterTime" : Timestamp(1606294533, 1), "signature" : { "hash" : BinData(0,"UDIIGdRByffSd7zBXbKOocNHVf4="), "keyId" : NumberLong("6856584343653974019") } } } glc-test:PRIMARY> db.system.profile.drop() 2020-11-25T16:55:53.233+0800 E QUERY [js] Error: drop failed: { "operationTime" : Timestamp(1606294543, 1), "ok" : 0, "errmsg" : "turn off profiling before dropping system.profile collection", "code" : 20, "codeName" : "IllegalOperation", "$clusterTime" : { "clusterTime" : Timestamp(1606294543, 1), "signature" : { "hash" : BinData(0,"IS5isA2D6B9TAnEsaW/SFsfwe+0="), "keyId" : NumberLong("6856584343653974019") } } } : _getErrorWithCode@src/mongo/shell/utils.js:25:13 DBCollection.prototype.drop@src/mongo/shell/collection.js:707:1 @(shell):1:1
glc-test:PRIMARY> db.setProfilingLevel(0) { "was" : 1, "slowms" : 500, "ratelimit" : 1, "sampleRate" : 1, "ok" : 1, "operationTime" : Timestamp(1606294563, 1), "$clusterTime" : { "clusterTime" : Timestamp(1606294563, 1), "signature" : { "hash" : BinData(0,"NT7TdpDLfjzC37lDMtINsmJvVQ0="), "keyId" : NumberLong("6856584343653974019") } } } glc-test:PRIMARY> db.system.profile.drop() true glc-test:PRIMARY>
三、创建慢查询集合：
db.createCollection("system.profile", {size: 40000000, capped: true})
具体例子如下：
glc-test:PRIMARY> show tables; glc glc-test:PRIMARY> db.createCollection("system.profile", {size: 40000000, capped: true}) { "ok" : 1, "operationTime" : Timestamp(1606294983, 1), "$clusterTime" : { "clusterTime" : Timestamp(1606294983, 1), "signature" : { "hash" : BinData(0,"vXiMidZUy7pXCg2t8Zvj4zgsO4E="), "keyId" : NumberLong("6856584343653974019") } } } glc-test:PRIMARY> show tables; glc system.profile glc-test:PRIMARY>
解读 db.system.profile.find().pretty()：
# "op" : "query",表示操作的类型，代表了该慢日志的种类是什么，是查询、插入、更新、删除还是其他。主要有： - insert
- query
- update
- remove
- getmore
- command
# "ns" : "igoodful.log" ：表示该慢日志是哪个库下的哪个集合所对应的慢日志。 # system.profile.nreturned ：该操作最终返回文档的数量； # system.profile.responseLength ：结果返回的大小，单位为bytes，该值如果过大，则需考虑limit()等方式减少输出结果；
# system.profile.millis ：该操作从开始到结束耗时多少，单位为毫秒；
# system.profile.execStats ：包含了一些该操作的统计信息，只有query类型的才会显示此项，包含查询操作的执行统计信息的文档。对于其他操作，该值为空文档。
# system.profile.execStats.stage ：查询类型
COLLSCAN用于收集扫描IXSCAN用于扫描索引键FETCH用于检索文件
# system.profile.ts ：该操作执行时的时间
# system.profile.locks： 全局、库、表的锁使用情况
# system.profile.PlanSummary：索引使用情况，有：
- collscan —— 全表扫描
- ixscan —— 索引扫描
- idhack —— 使用了默认的_id索引
- fetch —— 根据索引去检索某一个文档
- shard_metge —— 将各个分片的返回数据进行聚合
- sharding_filter —— 通过mongos对分片数据进行查询
# system.profile.numYield：让出锁
# system.profile.client ：哪个客户端发起的该操作，并显示出该客户端的ip或hostname
# system.profile.client ：
# system.profile.client ：
# system.profile.client ：
# system.profile.client ：
{ "op" : "query", "ns" : "igoodful.log", "command" : { "find" : "log", "filter" : { }, "sort" : { "t" : -1 }, "limit" : 1, "lsid" : { "id" : UUID("832477ad-a7e6-4bfc-9f2b-4b04538d77f3") }, "$clusterTime" : { "clusterTime" : Timestamp(1611211743, 4), "signature" : { "hash" : BinData(0,"bWjbtJwf0mD9oImjMxc1JTIElOk="), "keyId" : NumberLong("6908999957030633474") } }, "$db" : "igoodful", "$readPreference" : { "mode" : "primary" } }, "keysExamined" : 0, "docsExamined" : 173829, "hasSortStage" : true, "cursorExhausted" : true, "numYield" : 1358, "nreturned" : 1, "locks" : { "Global" : { "acquireCount" : { "r" : NumberLong(1361) } }, "Database" : { "acquireCount" : { "r" : NumberLong(1359) } }, "Collection" : { "acquireCount" : { "r" : NumberLong(1359) } } }, "storage" : { }, "responseLength" : 1005, "protocol" : "op_msg", "millis" : 669, "rateLimit" : 1, "planSummary" : "COLLSCAN", "execStats" : { "stage" : "SORT", "nReturned" : 1, "executionTimeMillisEstimate" : 77, "works" : 173834, "advanced" : 1, "needTime" : 173832, "needYield" : 0, "saveState" : 1358, "restoreState" : 1358, "isEOF" : 1, "invalidates" : 0, "sortPattern" : { "t" : -1 }, "memUsage" : 782, "memLimit" : 33554432, "limitAmount" : 1, "inputStage" : { "stage" : "SORT_KEY_GENERATOR", "nReturned" : 173829, "executionTimeMillisEstimate" : 35, "works" : 173832, "advanced" : 173829, "needTime" : 2, "needYield" : 0, "saveState" : 1358, "restoreState" : 1358, "isEOF" : 1, "invalidates" : 0, "inputStage" : { "stage" : "COLLSCAN", "nReturned" : 173829, "executionTimeMillisEstimate" : 15, "works" : 173831, "advanced" : 173829, "needTime" : 1, "needYield" : 0, "saveState" : 1358, "restoreState" : 1358, "isEOF" : 1, "invalidates" : 0, "direction" : "forward", "docsExamined" : 173829 } } }, "ts" : ISODate("2021-01-21T06:49:04.415Z"), "client" : "10.10.10.11", "allUsers" : [ { "user" : "igoodful_wr", "db" : "admin" } ], "user" : "igoodful_wr@admin" }
{ "timestamp": "Thu Apr 2 07:51:50.985" // 日期和时间, ISO8601格式 "severityLevel": "I" // 日志级别 I代表info的意思，其他的还有F,E,W,D等 "components": "COMMAND" //组件类别，不同组件打印出的日志带不同的标签，便于日志分类 "namespace": "animal.MongoUser_58" //查询的命名空间，即<databse.collection> "operation": "find" //操作类别，可能是[find,insert,update,remove,getmore,command] "command": { find: "MongoUser_58", filter: { $and: [ { lld: { $gte: 18351 } }, { fc: { $lt: 120 } }, { _id: { $nin: [1244093274 ] } },
{ $or: [ { rc: { $exists: false } }, { rc: { $lte: 1835400100 } } ] }, { lv: { $gte: 69 } }, { lv: { $lte: 99 } },
{ cc: { $in: [ 440512, 440513, 440514, 440500, 440515, 440511, 440523, 440507 ] } } ] }, limit: 30 } //具体的操作命令细节 "planSummary": "IXSCAN { lv: -1 }", // 命令执行计划的简要说明，当前使用了 lv 这个字段的索引。如果是全表扫描，则是COLLSCAN "keysExamined": 20856, // 该项表明为了找出最终结果MongoDB搜索了索引中的多少个key "docsExamined": 20856, // 该项表明为了找出最终结果MongoDB搜索了多少个文档 "cursorExhausted": 1, // 该项表明本次查询中游标耗尽的次数 "keyUpdates":0, // 该项表名有多少个index key在该操作中被更改，更改索引键也会有少量的性能消耗，因为数据库不单单要删除旧Key，还要插入新的Key到B-Tree索引中 "writeConflicts":0, // 写冲突发生的数量，例如update一个正在被别的update操作的文档 "numYields":6801, // 为了让别的操作完成而屈服的次数，一般发生在需要访问的数据尚未被完全读取到内存中，MongoDB会优先完成在内存中的操作 "nreturned":0, // 该操作最终返回文档的数量 "reslen":110, // 结果返回的大小，单位为bytes，该值如果过大，则需考虑limit()等方式减少输出结果 "locks": { // 在操作中产生的锁，锁的种类有多种，如下 Global: { acquireCount: { r: 13604 } }, //具体每一种锁请求锁的次数 Database: { acquireCount: { r: 6802 } }, Collection: { acquireCount: { r: 6802 } } }, "protocol": "op_command", // 消息的协议 "millis" : 69132, // 从 MongoDB 操作开始到结束耗费的时间，单位为ms }
解读db.currentOp()：
#################################################
京公网安备 11010502036488号