【mongoDB】根据日志诊断mongoDB CPU飙升原因

作者: Bogon | 来源:发表于2023-04-18 14:23 被阅读0次

MongoDB运行日志自动分割
MAMP环境安装mongodb扩展
ubuntu18.04 安装mongoDB
MongoDB 初探
mongo-java-driver 中log4j对其日志的管理
【mongoDB】MongoDB的 4种日志
排查MongoDB CPU使用率高的问题
mongodb按天查询数量
十分钟搞定mongodb副本集
MongoDB中有几种日志？

$ tail -f /path/to/mongodb.log

27605381670447,"collection":"testColl","$db":"testDB"},"originatingCommand":{"find":"testColl","filter":{"task_id":"b6a65d37-04db-4699-a02a-a2a08496dad4","msg":{"$regex":{"$regularExpression":{"pattern":"(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|$)","options":"i"}}}},"skip":0,"$db":"testDB"},"planSummary":"IXSCAN { task_id: 1, seq: 1 }","cursorid":5052427605381670447,"keysExamined":408695,"docsExamined":408695,"cursorExhausted":true,"numYields":440,"nreturned":18646,"reslen":5473979,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":441}},"Global":{"acquireCount":{"r":441}},"Database":{"acquireCount":{"r":441}},"Collection":{"acquireCount":{"r":441}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_query","durationMillis":3101}}


{"t":{"$date":"2023-04-19T10:42:38.302+08:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn854","msg":"Slow query","attr":{"type":"command","ns":"testDB.testColl","command":{"getMore":9111477179350825603,"collection":"testColl","$db":"testDB"},"originatingCommand":{"find":"testColl","filter":{"task_id":"b6a65d37-04db-4699-a02a-a2a08496dad4","msg":{"$regex":{"$regularExpression":{"pattern":"(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|$)","options":"i"}}}},"skip":0,"$db":"testDB"},"planSummary":"IXSCAN { task_id: 1, seq: 1 }","cursorid":9111477179350825603,"keysExamined":408220,"docsExamined":408220,"cursorExhausted":true,"numYields":474,"nreturned":18729,"reslen":5497277,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":475}},"Global":{"acquireCount":{"r":475}},"Database":{"acquireCount":{"r":475}},"Collection":{"acquireCount":{"r":475}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_query","durationMillis":8178}}


{"t":{"$date":"2023-04-19T10:56:36.952+08:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn952","msg":"Slow query","attr":{"type":"command","ns":"testDB.testColl","appName":"crawlab","command":{"getMore":4693332694208760066,"collection":"testColl","$db":"testDB"},"originatingCommand":{"find":"testColl","filter":{"task_id":"f64c8ac4-69aa-4fac-9766-05d4b197decf","msg":{"$regex":{"$regularExpression":{"pattern":"(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|$)","options":"i"}}}},"skip":0,"$db":"testDB"},"planSummary":"IXSCAN { task_id: 1, seq: 1 }","cursorid":4693332694208760066,"keysExamined":255713,"docsExamined":255713,"cursorExhausted":true,"numYields":273,"nreturned":12607,"reslen":3679996,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":274}},"Global":{"acquireCount":{"r":274}},"Database":{"acquireCount":{"r":274}},"Collection":{"acquireCount":{"r":274}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_query","durationMillis":6709}}

> use  testDB


> db.testColl.findOne()  
{
        "_id" : ObjectId("643dfcfbf23397002ed07402"),
        "msg" : "2023-04-18 10:14:19.929 | INFO     | __main__:get_scenic_comment:116 - 你好，test,第59页数据成功！",
        "task_id" : "4e0a485a-d7a8-4147-bade-6e1109838ae8",
        "seq" : NumberLong(4310),
        "ts" : ISODate("2023-04-18T02:14:19.929Z"),
        "expire_ts" : ISODate("2023-04-19T02:14:19.929Z")
}

> db. testColl.getIndexes() 
[
        {
                "v" : 2,
                "key" : {
                        "_id" : 1
                },
                "name" : "_id_"
        },
        {
                "v" : 2,
                "key" : {
                        "task_id" : 1,
                        "seq" : 1
                },
                "name" : "task_id_1_seq_1"
        },
        {
                "v" : 2,
                "key" : {
                        "task_id" : 1,
                        "msg" : 1
                },
                "name" : "task_id_1_msg_1"
        },
        {
                "v" : 2,
                "key" : {
                        "expire_ts" : 1
                },
                "name" : "expire_ts_1",
                "sparse" : true,
                "expireAfterSeconds" : 1
        }
]

这是一个MongoDB的索引查询结果，显示了testColl表的所有索引信息。其中：

第一个索引是默认的_id索引，它是MongoDB自动创建的，用于唯一标识每个文档。
第二个索引是task_id和seq字段的联合索引，按升序排序。这个索引可以用于查询特定任务ID下的多个序列，或者按序列号排序查询。
第三个索引是task_id和msg字段的联合索引，按升序排序。这个索引可以用于查询特定任务ID下的多个消息，或者按消息内容排序查询。
第四个索引是expire_ts字段的单独索引，按升序排序。这个索引是一个稀疏索引，只包含具有expire_ts字段的文档，而且设置了过期时间。
这个索引可以用于查询过期的文档，并在一定时间后自动删除它们。

以下是mongoDB日志，请做一个解析说明

{"t":{"date":"2023-04-19T10:42:38.302+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn854","msg":"Slow query","attr":{"type":"command","ns":"testDB.testColl","command":{"getMore":9111477179350825603,"collection":"testColl","db":"testDB"},"originatingCommand":{"find":"testColl","filter":{"task_id":"b6a65d37-04db-4699-a02a-a2a08496dad4","msg":{"regex":{"regularExpression":{"pattern":"(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|)","options":"i"}}}},"skip":0,"db":"testDB"},"planSummary":"IXSCAN { task_id: 1, seq: 1 }","cursorid":9111477179350825603,"keysExamined":408220,"docsExamined":408220,"cursorExhausted":true,"numYields":474,"nreturned":18729,"reslen":5497277,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":475}},"Global":{"acquireCount":{"r":475}},"Database":{"acquireCount":{"r":475}},"Collection":{"acquireCount":{"r":475}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_query","durationMillis":8178}}

该MongoDB日志记录了一次慢查询。具体内容如下：

- "t": 日志时间戳
- "s": 日志级别，这里为 "I"，表示信息级别
- "c": 日志分类，这里为 "COMMAND"，表示该日志记录的是MongoDB命令的执行情况
- "id": 日志ID
- "ctx": 连接上下文，这里为 "conn854"，表示该命令的执行是在连接上下文为 "conn854" 的客户端发起的
- "msg": 日志信息，这里为 "Slow query"，表示该命令执行的比较慢，超过了MongoDB的慢查询阈值
- "attr": 附加属性，记录了该命令执行的详细信息，包括：

  - "type": 命令类型，这里为 "command"
  - "ns": 命名空间，这里为 "testDB.testColl"，表示该命令是针对 "testDB" 数据库中的 "testColl" 集合执行的
  - "command": 命令内容，这里为 {"getMore":9111477179350825603,"collection":"testColl","db":"testDB"}，表示该命令是执行 "testColl" 集合的 getMore 操作，获取更多的查询结果
  - "originatingCommand": 原始命令，这里为 {"find":"testColl","filter":{"task_id":"b6a65d37-04db-4699-a02a-a2a08496dad4","msg":{"regex":{"regularExpression":{"pattern":"(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|)","options":"i"}}}},"skip":0,"db":"testDB"}，表示该命令的原始操作是在 "testColl" 集合中执行了一个 find 操作，查询符合条件的文档，条件为 task_id 字段为 "b6a65d37-04db-4699-a02a-a2a08496dad4"，且 msg 字段中匹配正则表达式 "(?:[ :,.]|^)((?:error|exception|traceback)s?)(?:[ :,.]|)"
  - "planSummary": 查询计划概要，这里为 "IXSCAN { task_id: 1, seq: 1 }"，表示该查询使用了 task_id 和 seq 字段的索引
  - "cursorid": 游标ID，这里为 9111477179350825603，表示该查询的游标ID
  - "keysExamined": 索引键被检查的次数，这里为 408220
  - "docsExamined": 被检查的文档数，这里为 408220
  - "cursorExhausted": 游标是否已经用完，这里为 true，表示该查询已经返回了所有的结果
  - "numYields": 该查询在执行过程中释放了多少次CPU，这里为 474
  - "nreturned": 返回的文档数，这里为 18729
  - "reslen": 返回的文档总大小，这里为 5497277
  - "locks": 锁状态，包括 ReplicationStateTransition、Global、Database、Collection 和 Mutex 等级别的锁的获取次数，这里表示在执行该查询的过程中获取了一些锁
  - "storage": 存储状态，这里为空，表示该查询没有对存储状态产生影响
  - "protocol": 协议类型，这里为 "op_query"，表示该命令使用的是MongoDB的查询协议
  - "durationMillis": 命令执行时间，这里为 8178 毫秒，表示该命令执行了 8.178 秒。

该命令执行了 8.178 秒，有什么优化建议？

根据该MongoDB日志记录的信息，可以给出以下优化建议：

索引优化：该查询使用了 task_id 和 seq 字段的索引，但是在查询过程中还是检查了 408220 个索引键和文档，建议进一步优化索引，确保查询时能够充分利用索引，减少检查的索引键和文档数量。
查询条件优化：该查询的查询条件中包含了一个正则表达式，正则表达式的匹配操作通常比较耗时，建议尽量避免在查询条件中使用正则表达式，或者使用更简单的匹配方式，如字符串相等等。
分页优化：该查询返回的文档数较多，有 18729 个文档，建议考虑使用分页的方式进行查询，减少一次性返回的文档数量，提高查询效率。
硬件优化：如果以上优化措施都已经实施，但查询仍然较慢，可以考虑优化硬件，如增加CPU、内存等资源，提高MongoDB的性能表现。

MongoDB运行日志自动分割
所谓自动分割MongoDB日志文件，就是指Rotate MongoDB log files，即让MongoDB每天...
MAMP环境安装mongodb扩展
搜索可用的mongodb组件 brew search mongodb 根据本机php版本安装对应的mongodb ...
ubuntu18.04 安装mongoDB
安装MongoDB 下载mongodb软件包从mongoDB下载软件包解压建立数据目录建立日志目录添加环境...
MongoDB 初探
这次用mongoDB 只是存储请求日志。 1.mongodb是什么？ MongoDB 是由C++语言编写的，是一个...
mongo-java-driver 中log4j对其日志的管理
在项目中引用了mongodb-java-driver的jar包后，日志多出很多mongodb操作的日志，导致自己找...
【mongoDB】MongoDB的 4种日志
任何一种数据库都有各种各样的日志，MongoDB也不例外。 MongoDB中有4种日志：分别是系统日志（log）、...
排查MongoDB CPU使用率高的问题
排查MongoDB CPU使用率高的问题
mongodb按天查询数量
1、引言最近做报表，日志都是存入mongodb，所以需要从mongodb统计查询。需求：1、按天查询当天日志条...
十分钟搞定mongodb副本集
mongodb副本集配置最近项目中用到了mongodb,由于是用mongodb来记录一些程序的日志信息和日...
MongoDB中有几种日志？
任何一种数据库都有各种各样的日志，MongoDB也不例外。MongoDB中有4种日志，分别是系统日志、Journa...