日志消息
Overview
正常运行中，MongoDB 维护事件的运行日志，包括传入连接、运行的命令和遇到的问题等条目。通常，日志消息可用于诊断问题、监控部署和调优性能。
您可以使用以下方法获取日志消息：
在您配置的日志目标中查看日志。
运行
getLog命令。通过 MongoDB Atlas 下载日志。要了解更多信息，请参阅下载日志。
结构化日志
mongod / mongos 实例以结构化 JSON 格式输出所有日志消息。日志条目以一系列键值对的形式编写，每个键表示日志消息字段类型，例如“严重性”，每个对应的值记录该字段类型的关联日志信息，例如“信息”。以前，日志条目以纯文本形式输出。
例子
以下是 MongoDB 日志文件中可能出现的 JSON 格式的示例日志消息：
{"t":{"$date":"2020-05-01T15:16:17.180+00:00"},"s":"I", "c":"NETWORK", "id":12345, "ctx":"listener", "svc": "R", "msg":"Listening on", "attr":{"address":"127.0.0.1"}}
JSON 日志条目可以美观打印，以提高可读性。这是相同的日志条目的美观打印结果：
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
例如，在此日志条目中，键 s 表示严重性，相应的值 I 表示“信息性”，键 c 表示组件，相应的值 NETWORK 表示“网络”组件负责此特定消息。日志消息字段类型部分详细介绍了各种字段类型。
键值对的结构化日志记录有助于通过自动化工具或日志摄取服务进行高效解析，并使日志消息的编程搜索和分析更容易执行。分析结构化日志消息的示例可以在解析结构化日志消息部分找到。
注意
如果无法写入日志文件，mongod 会退出。为了确保 mongod 可以写入日志文件，请验证日志卷在磁盘上是否有空间并且日志已轮换。
JSON 日志输出格式
所有日志输出均采用 JSON 格式，包括发送至以下目标的输出：
日志文件
Syslog
Stdout（标准输出）日志目的地
getLog 命令的输出也是 JSON 格式。
每个日志条目以自包含 JSON 对象的形式输出，该对象遵循宽松扩展 JSON v2.0 规范，具有以下布局和字段顺序：
{ "t": <Datetime>, // timestamp "s": <String>, // severity "c": <String>, // component "id": <Integer>, // unique identifier "ctx": <String>, // context "svc": <String>, // service "msg": <String>, // message body "attr": <Object>, // additional attributes (optional) "tags": <Array of strings>, // tags (optional) "truncated": <Object>, // truncation info (if truncated) "size": <Object> // original size of entry (if truncated) }
字段说明：
字段名称 | 类型 | 说明 |
|---|---|---|
| 日期时间 | ISO-8601 格式的日志消息时间戳。有关示例，请参阅时间戳。 |
| 字符串 | |
| 字符串 | |
| 整型 | |
| 字符串 | 产生日志语句的线程的名称。 |
| 字符串 | 在其上下文中发出日志声明的服务的名称。 将为 |
| 字符串 | |
| 对象 | One or more key-value pairs for additional log attributes. If a log message does not include any additional attributes, the attr object is omitted.Attribute values may be referenced by their key name in the msg message body, depending on the message. If necessary, theattributes are escaped according to the JSON specification. |
| 字符串数组 | 表示适用于日志语句的任何标签的字符串。例如： |
| 对象 | |
| 对象 |
转义
根据宽松扩展 JSON v2.0 规范，消息和属性字段会根据需要对控制字符进行转义：
所代表的字符 | 转义序列 |
|---|---|
引号 ( |
|
Backslash ( |
|
退格 ( |
|
进纸 ( |
|
换行符 ( |
|
回车 ( |
|
Horizontal tab ( |
|
上面未列出的控制字符使用 \uXXXX 进行转义，其中 "XXXX" 是十六进制的 unicode 代码点。具有无效 UTF-8 编码的字节将替换为 \ufffd 表示的 unicode 替换字符。
消息转义的示例请参阅示例部分。
截断
在版本7.3中进行了更改。
任何超过 maxLogSizeKB 定义的最大大小（默认值：10 KB）的属性都将被截断。截断的属性会省略超出配置限制的日志数据，但保留条目的 JSON 格式，以确保条目仍可解析。
示例，以下JSON对象表示command属性，该属性在$in字段中包含未截断的5000元素。
注意
为了便于阅读，对示例日志条目进行了重新格式化。
{ "command": { "find": "mycoll", "filter": { "value1": { "$in": [0, 1, 2, 3, ... 4999] }, "value2": "foo" }, "sort": { "value1": 1 }, "lsid":{"id":{"$uuid":"80a99e49-a850-467b-a26d-aeb2d8b9f42b"}}, "$db": "testdb" } }
在此示例中，$in 数组在第 376 个元素处被截断，因为如果包含后续元素，command 属性的大小将超过 maxLogSizeKB。command 属性的其余部分被省略。截断的日志条目类似于以下输出：
{ "t": { "$date": "2021-03-17T20:30:07.212+01:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn9", "msg": "Slow query", "attr": { "command": { "find": "mycoll", "filter": { "value1": { "$in": [ 0, 1, ..., 376 ] // Values in array omitted for brevity } } }, ... // Other attr fields omitted for brevity }, "truncated": { "command": { "truncated": { "filter": { "truncated": { "value1": { "truncated": { "$in": { "truncated": { "377": { "type": "double", "size": 8 } }, "omitted": 4623 } } } }, "omitted": 1 } }, "omitted": 3 } }, "size": { "command": 21692 } }
包含一个或多个截断属性的日志条目包括嵌套的truncated对象，该对象为日志条目中的每个截断属性提供以下信息：
被截断的属性
触发截断的该属性的特定子对象（如果适用）
截断字段的数据
type触发截断的元素的
size（以字节为单位）每个子对象下因截断而为
omitted的元素数量
具有截断属性的日志条目还可能在条目末尾包含一个额外的size字段，该字段指示截断之前属性的原始大小，在本例中为21692或大约22 KB。 仅当最终的size字段与truncated对象中的size字段不同时，即属性的总对象大小与截断的子对象的大小不同时，才会显示上示例中的情况。
填充
输出到文件或系统日志日志目的地时，会在严重性、上下文和 id 字段之后添加填充，从而提高使用固定宽度字体查看时的可读性。
以下 MongoDB 日志文件摘录演示了这种填充：
{"t":{"$date":"2020-05-18T20:18:12.724+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main", "svc": "R", "msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"} {"t":{"$date":"2020-05-18T20:18:12.734+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main", "svc": "R", "msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2020-05-18T20:18:12.734+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "ctx":"main", "svc": "R", "msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten", "svc": "R", "msg":"MongoDB starting", "attr":{"pid":10111,"port":27001,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"centos8"}} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten", "svc": "R", "msg":"Build Info", "attr":{"buildInfo":{"version":"4.4.0","gitVersion":"328c35e4b883540675fb4b626c53a08f74e43cf0","openSSLVersion":"OpenSSL 1.1.1c FIPS 28 May 2019","modules":[],"allocator":"tcmalloc","environment":{"distmod":"rhel80","distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten", "svc": "R", "msg":"Operating System", "attr":{"os":{"name":"CentOS Linux release 8.0.1905 (Core) ","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}
美观打印
在使用 MongoDB 结构化日志时，第三方 jq 命令行实用程序非常有用，可以轻松美观地打印日志条目，并提供强大的基于键的匹配和过滤功能。
jq 是一个开源 JSON 解析器，用于 Linux、Windows 和 macOS。
可以使用 jq 来美化日志条目的打印，如下所示：
美观打印整个日志文件：
cat mongod.log | jq 美观打印最新的日志条目：
cat mongod.log | tail -1 | jq
有关使用 MongoDB 结构化日志的更多示例，请参阅解析结构化日志消息部分。
配置日志消息目的地
MongoDB 日志消息可以输出到文件、系统日志或 stdout（标准输出）。
要配置日志输出目的地，可在配置文件或命令行中使用以下设置
- 配置文件：
文件或系统日志的
systemLog.destination选项
- 命令行：
不指定文件或系统日志会将所有日志输出发送到标准输出。
有关日志记录设置和选项的完整列表，请参阅：
注意
发送到 stderr（标准误）的错误消息，例如启动期间不使用文件或系统日志日志目标时发生的致命错误，或与配置错误的日志记录设置有关的消息，不受日志输出目标设置的影响，并且以纯文本格式打印到 stderr。
日志消息字段类型
时间戳
时间戳字段类型指示记录的事件发生的确切日期和时间。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
记录到文件或系统日志[1]时，时间戳的默认格式为 iso8601-local。要修改时间戳格式，请使用 --timeStampFormat 运行时选项或 systemLog.timeStampFormat 设置。
请参阅按日期范围过滤，查看过滤时间戳字段的解析示例。
注意
ctime 时间戳格式不再受支持。
| [1] | 如果记录到系统日志，syslog 守护进程会在记录消息时生成时间戳，而不是在 MongoDB 发布消息时生成时间戳。这可能会导致日志条目的时间戳具有误导性，尤其是当系统负载较重时。 |
严重性
严重性字段类型表示与记录的事件关联的严重性级别。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
严重性级别从“致命”（最严重）到“调试”（最不严重）：
等级 | 说明 |
|---|---|
| 致命 |
| 错误 |
| 警告 |
| |
|
您可以指定各个组件的详细程度，以决定 MongoDB 输出的信息和调试消息的量。高于这些级别的严重性类别始终会显示。[2] 要设置详细级别，请参阅配置日志详细级别。
组件
组件字段类型表示记录的事件所属的类别，例如网络或命令。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
每个组件均可通过自己的详细级别过滤器进行单独配置。可用的组件如下：
ACCESS与访问控制（例如身份验证）相关的消息。要指定
ACCESS组件的日志级别，请使用systemLog.component.accessControl.verbosity设置。
COMMAND与数据库命令（例如
count）有关的消息。要指定COMMAND组件的日志级别，请使用systemLog.component.command.verbosity设置。
CONTROL与控制活动（例如初始化）相关的消息。要指定
CONTROL组件的日志级别，请使用systemLog.component.control.verbosity设置。
ELECTION与副本集选举特别相关的消息。要指定
ELECTION组件的日志级别，请设置systemLog.component.replication.election.verbosity参数。REPL是ELECTION的父组件。如果systemLog.component.replication.election.verbosity未设置，则 MongoDB 将把REPL详细级别用于ELECTION组件。
FTDC与诊断数据收集机制相关的消息，例如服务器统计信息和状态消息。要指定
FTDC组件的日志级别，请使用systemLog.component.ftdc.verbosity设置。
GEO与地理空间形状解析相关的消息，例如验证 GeoJSON 形状。要指定
GEO组件的日志级别，请设置systemLog.component.geo.verbosity参数。
INDEX与索引操作（例如创建索引）相关的消息。要指定
INDEX组件的日志级别，请设置systemLog.component.index.verbosity参数。
INITSYNC与初始同步操作相关的消息。要指定
INITSYNC组件的日志级别，请设置systemLog.component.replication.initialSync.verbosity参数。REPL是INITSYNC的父组件。如果systemLog.component.replication.initialSync.verbosity未设置，则 MongoDB 将把REPL详细级别用于INITSYNC组件。
JOURNAL与存储日志活动明确相关的消息。要指定
JOURNAL组件的日志级别，请使用systemLog.component.storage.journal.verbosity设置。STORAGE是JOURNAL的父组件。如果systemLog.component.storage.journal.verbosity未设置，则 MongoDB 将把STORAGE详细级别用于JOURNAL组件。
NETWORK与网络活动相关的消息，例如接受连接。要指定
NETWORK组件的日志级别，请设置systemLog.component.network.verbosity参数。
QUERY与查询相关的消息，包括查询规划器活动。要指定
QUERY组件的日志级别，请设置systemLog.component.query.verbosity参数。
QUERYSTATS与
$queryStats操作相关的消息。 要指定QUERYSTATS组件的日志级别，请设立systemLog.component.queryStats.verbosity参数。
RECOVERY与存储恢复活动相关的消息。要指定
RECOVERY组件的日志级别，请使用systemLog.component.storage.recovery.verbosity设置。STORAGE是RECOVERY的父组件。如果systemLog.component.storage.recovery.verbosity未设置，则 MongoDB 将把STORAGE详细级别用于RECOVERY组件。
REPL与副本集相关的消息，例如初始同步、心跳、稳态复制和回滚。[2] 要指定
REPL组件的日志级别，请设置systemLog.component.replication.verbosity参数。
REPL_HB专门与副本集心跳相关的消息。要指定
REPL_HB组件的日志级别，请设置systemLog.component.replication.heartbeats.verbosity参数。REPL是REPL_HB的父组件。如果systemLog.component.replication.heartbeats.verbosity未设置，则 MongoDB 将把REPL详细级别用于REPL_HB组件。
ROLLBACK与回滚操作有关的消息。要指定
ROLLBACK组件的日志级别，请设置systemLog.component.replication.rollback.verbosity参数。REPL是ROLLBACK的父组件。如果systemLog.component.replication.rollback.verbosity未设置，则 MongoDB 将把REPL详细级别用于ROLLBACK组件。
SHARDING与分片活动有关的信息，例如启动
mongos。要指定SHARDING组件的日志级别，请使用systemLog.component.sharding.verbosity设置。
STORAGE与存储活动有关的信息，例如
fsync命令中涉及的进程。要指定STORAGE组件的日志级别，请使用systemLog.component.storage.verbosity设置。
TXN与多文档事务相关的消息。要指定
TXN组件的日志级别，请使用systemLog.component.transaction.verbosity设置。
WRITE与写入操作相关的消息，例如
update命令。要指定WRITE组件的日志级别，请使用systemLog.component.write.verbosity设置。
WT5.3 版本中的新增功能。
与 WiredTiger 存储引擎相关的消息。要指定
WT组件的日志级别，请使用systemLog.component.storage.wt.verbosity设置。
WTBACKUP5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的备份操作相关的消息。要指定
WTBACKUP组件的日志级别，请使用systemLog.component.storage.wt.wtBackup.verbosity设置。
WTCHKPT5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的检查点操作相关的消息。要指定
WTCHKPT组件的日志级别，请使用systemLog.component.storage.wt.wtCheckpoint.verbosity设置。
WTCMPCT5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的压缩操作相关的消息。要指定
WTCMPCT组件的日志级别，请使用systemLog.component.storage.wt.wtCompact.verbosity设置。
WTEVICT5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的驱逐操作相关的消息。要指定
WTEVICT组件的日志级别，请使用systemLog.component.storage.wt.wtEviction.verbosity设置。
WTHS5.3 版本中的新增功能。
与 WiredTiger 存储引擎的历史存储相关的消息。要指定
WTHS组件的日志级别，请使用systemLog.component.storage.wt.wtHS.verbosity设置。
WTRECOV5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的恢复操作相关的消息。要指定
WTRECOV组件的日志级别，请使用systemLog.component.storage.wt.wtRecovery.verbosity设置。
WTRTS5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的回滚到稳定 (RTS) 操作相关的消息。要指定
WTRTS组件的日志级别，请使用systemLog.component.storage.wt.wtRTS.verbosity设置。
WTSLVG5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的抢救操作相关的消息。要指定
WTSLVG组件的日志级别，请使用systemLog.component.storage.wt.wtSalvage.verbosity设置。
WTTS5.3 版本中的新增功能。
与 WiredTiger 存储引擎使用的时间戳相关的消息。要指定
WTTS组件的日志级别，请使用systemLog.component.storage.wt.wtTimestamp.verbosity设置。
WTTXN5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的事务相关的消息。要指定
WTTXN组件的日志级别，请使用systemLog.component.storage.wt.wtTransaction.verbosity设置。
WTVRFY5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的验证操作相关的消息。要指定
WTVRFY组件的日志级别，请使用systemLog.component.storage.wt.wtVerify.verbosity设置。
WTWRTLOG5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的日志写入操作相关的消息。要指定
WTWRTLOG组件的日志级别，请使用systemLog.component.storage.wt.wtWriteLog.verbosity设置。
-与命名组件不相关的消息。在
systemLog.verbosity设置中指定未命名组件的默认日志级别。systemLog.verbosity设置是已命名和未命名组件的默认设置。
请参阅按组件过滤，了解按照组件字段过滤的日志解析示例。
客户端数据
MongoDB 驱动程序和客户端应用程序（包括 mongosh）能够在连接到服务器时发送标识信息。连接建立后，客户端不会再次发送标识信息，除非连接断开并重新建立。
该标识信息包含在日志条目的属性字段中。所包含的确切信息因客户端而异。
以下是包含从 mongosh 连接传输的客户端数据文档的示例日志消息。客户端数据包含在属性字段的 doc 对象中：
{"t":{"$date":"2020-05-20T16:21:31.561+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn202", "svc": "R", "msg":"client metadata", "attr":{"remote":"127.0.0.1:37106","client":"conn202","doc":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"4.4.0"},"os":{"type":"Linux","name":"CentOS Linux release 8.0.1905 (Core) ","architecture":"x86_64","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}}
当副本集从节点发起与主节点的连接时，从节点会发送类似的数据。包含此启动连接的示例日志消息可能如下所示。客户端数据包含在属性字段的 doc 对象中：
{"t":{"$date":"2020-05-20T16:33:40.595+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn214", "svc": "R", "msg":"client metadata", "attr":{"remote":"127.0.0.1:37176","client":"conn214","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.0"},"os":{"type":"Linux","name":"CentOS Linux release 8.0.1905 (Core) ","architecture":"x86_64","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}}
有关客户端信息和必填字段的完整描述，请参阅MongoDB 握手规范。
详细程度
您可以指定日志记录详细级别以增加或减少 MongoDB 输出的日志消息量。可以同时调整所有组件的详细程度，也可以单独调整特定命名组件的详细程度。
详细级别仅影响严重性类别信息和调试中的日志条目。高于这些级别的严重性类别始终会显示。
您可以将详细程度设置为较高的值，以显示调试或开发的详细日志，或者设置为较低的值，以在经过审查的生产部署中尽量减少写入日志的操作。[2]
查看当前日志详细级别
要查看当前的详细级别，请使用 db.getLogComponents() 方法：
db.getLogComponents()
输出可能如下所示：
{ "verbosity" : 0, "accessControl" : { "verbosity" : -1 }, "command" : { "verbosity" : -1 }, ... "storage" : { "verbosity" : -1, "recovery" : { "verbosity" : -1 }, "journal" : { "verbosity" : -1 } }, ...
最初的 verbosity 条目是所有组件的父组件详细级别，而后面的各个命名组件（例如 accessControl）表示该组件的特定详细级别，如果设置，则会覆盖该特定组件的全局详细级别。
值为 -1，如果有父组件，则表示该组件继承父组件的详细级别（如上面的 recovery，继承 storage），如果没有父组件，则表示继承全局详细级别 command。如需了解详细级别的继承关系，请参阅组件部分。
配置日志详细级别
要配置详细级别，可以使用：systemLog.verbosity 和 systemLog.component.<name>.verbosity 设置、logComponentVerbosity 参数或 db.setLogLevel() 方法。[2]
systemLog 详细级别设置
要为所有组件配置默认日志级别，请使用 systemLog.verbosity 设置。要配置特定组件的级别，请使用 systemLog.component.<name>.verbosity 设置。
例如，以下配置将 systemLog.verbosity 设置为 1，将 systemLog.component.query.verbosity 设置为 2，将 systemLog.component.storage.verbosity 设置为 2，将 systemLog.component.storage.journal.verbosity 设置为 1：
systemLog: verbosity: 1 component: query: verbosity: 2 storage: verbosity: 2 journal: verbosity: 1
您将在配置文件或命令行中为 mongod 或 mongos 实例设置这些值。
所有未在配置中显式指定的组件的详细级别均为 -1，如果有父组件，则表示继承父组件的详细级别；如果没有，则表示继承全局详细级别 (systemLog.verbosity)。
logComponentVerbosity Parameter
要设置 logComponentVerbosity 参数，请传递一个包含要更改的详细级别设置的文档。
例如，以下将 default verbosity level 设置为 1，将 query 设置为 2，将 storage 设置为 2，将 storage.journal 设置为 1：
db.adminCommand( { setParameter: 1, logComponentVerbosity: { verbosity: 1, query: { verbosity: 2 }, storage: { verbosity: 2, journal: { verbosity: 1 } } } } )
您可以从 mongosh 设置这些值。
db.setLogLevel()
使用 db.setLogLevel() 方法更新单个组件的日志级别。对于组件，您可以指定 0 到 5 的详细级别，也可以指定 -1 以继承父组件的详细级别。例如，以下内容将 systemLog.component.query.verbosity 设置为其父级详细级别（即 默认详细级别）：
db.setLogLevel(-1, "query")
可以从 mongosh 设置这个值。
| [2] | （1、2、3、4、5）副本集的从节点成员现在记录需要比慢操作阈值更长的时间才能应用 oplog 条目。这些慢 oplog 消息：
|
记录慢操作
客户端操作（如查询）出现在日志中的条件是：其持续时间超过慢速操作阈值，或者日志详细程度为 1 或更高。[2] 这些日志条目包括与该操作相关的完整命令对象。
用于读/写操作的分析器条目和诊断日志消息（即 mongod/mongos 日志消息）包括：
planCacheShapeHash帮助识别具有相同计划缓存查询结构的慢查询。从 MongoDB 8.0 开始，预先存在的
queryHash字段被重命名为planCacheShapeHash。如果正在使用早期版本的 MongoDB，您将看到queryHash而不是planCacheShapeHash。planCacheKey更深入地了解慢查询的查询计划缓存。
从 MongoDB 5.0 开始，慢速操作日志消息包含指定客户端 IP 地址的 remote 字段。
从 MongoDB 6.2 开始，慢操作日志消息包含 queryFramework 字段，指示哪个查询引擎执行了该查询：
queryFramework: "classic"表示经典引擎完成该查询。queryFramework: "sbe"表示基于槽的查询执行引擎执行该查询。
从 MongoDB 6.1 开始。慢操作日志消息包含缓存刷新时间字段。
从 MongoDB 6.3 开始，慢操作日志消息和数据库分析器条目包含 cpuNanos 字段，该字段指定查询操作所花费的总 CPU 时间（以纳秒为单位）。cpuNanos 字段仅在 Linux 系统上可用。
从 MongoDB 7.0 （和6.0.13开始， 5.0.24 ），慢查询日志消息中的totalOplogSlotDurationMicros显示写入操作获取提交时间戳以提交存储引擎写入内容与实际提交之间的时间。 mongod支持并行写入。 但是，它可以按任意顺序提交带有提交时间戳的写操作。
例子
考虑以下带有提交时间戳的写入：
writeA with Timestamp1
writeB with Timestamp2
writeC with Timestamp3
假设 WriteB 首先在 Timestamp2 提交。复制暂停到 writeA 提交，因为需要 writeA 的带 Timestamp1 的 oplog 条目才能将 oplog 复制到副本集从节点。
从 MongoDB 8.0 开始，查询结构的 queryShapeHash 字段（如果可用）也包含在慢查询日志中。
并且，从 MongoDB 8.0开始，慢查询输出包括一个 queues 文档，其中包含有关操作队列的信息。queues 字段中的每个队列都包含一个 totalTimeQueuedMicros 字段，该字段包含操作在相应队列中花费的总累积时间（以微秒为单位）。
等待分片登录到remoteOpWaitMillis 字段的时间
版本 5.0 中的新增功能。
从 MongoDB 5.0 开始，可以使用 remoteOpWaitMillis 日志字段来获取分片结果的等待时间（以毫秒为单位）。
remoteOpWaitMillis 仅记录：
要确定合并操作或分片问题是否导致查询缓慢，请比较日志中的 workingMillis 和 remoteOpWaitMillis 时间字段。workingMillis 是查询完成所需的总时间。具体而言：
如果
workingMillis比remoteOpWaitMillis稍长，则大部分时间都花在等待分片响应上。例如，workingMillis为 17，remoteOpWaitMillis为 15。如果
workingMillis明显长于remoteOpWaitMillis，则大部分时间都花在执行合并上。例如，workingMillis为 100，remoteOpWaitMillis为 15。
日志编辑 (Redaction)
Queryable Encryption 日志校订
使用 Queryable Encryption 时，慢查询日志中会省略针对已加密集合的增删改查操作。有关详细信息，请参阅 Queryable Encryption 日志校订。
Enterprise 日志校订
仅在 MongoDB Enterprise 中可用。
使用 redactClientLogData 运行的 mongod 或 mongos 会在记录之前编辑与校订给定日志事件附带的任何消息，只留下与该事件相关的元数据、源文件或行号。redactClientLogData 以诊断细节为代价，防止潜在的敏感信息进入系统日志。
例如，以下操作将文档插入到不进行日志校订的 mongod 运行中。mongod 将日志详细级别设置为 1：
db.clients.insertOne( { "name" : "Joe", "PII" : "Sensitive Information" } )
此操作会产生以下日志事件：
{ "t": { "$date": "2024-07-19T15:36:55.024-07:00" }, "s": "I", "c": "COMMAND", ... "attr": { "type": "command", ... "appName": "mongosh 2.2.10", "command": { "insert": "clients", "documents": [ { "name": "Joe", "PII": "Sensitive Information", "_id": { "$oid": "669aea8792c7fd822d3e1d8c" } } ], "ordered": true, ... } ... } }
当 mongod 结合 redactClientLogData 运行并执行相同的插入操作时，会产生以下日志事件：
{ "t": { "$date": "2024-07-19T15:36:55.024-07:00" }, "s": "I", "c": "COMMAND", ... "attr": { "type": "command", ... "appName": "mongosh 2.2.10", "command": { "insert": "###", "documents": [ { "name": "###", "PII": "###", "_id": "###" } ], "ordered": "###", ... } ... } }
将 redactClientLogData 与静态加密和 TLS/SSL（传输加密）结合使用，以帮助遵守监管要求。
解析结构化日志消息
日志解析是以编程方式搜索和分析日志文件的行为，通常自动进行。随着引入结构化日志记录，日志解析变得更简单、更强大。例如：
日志消息字段以键值对的形式显示。日志解析器可以按照感兴趣的特定键查询，以有效地筛选结果。
日志消息始终包含相同的消息结构。日志解析器能可靠地从任何日志消息中提取信息，无需针对信息丢失或格式不同的情况进行编码。
以下示例展示使用 MongoDB JSON 日志输出时的常见日志解析工作流程。
日志解析示例
在使用 MongoDB 结构化日志时，第三方 jq 命令行实用程序 非常有用，可以轻松美观地打印日志条目，并提供强大的基于键的匹配和过滤功能。
jq 是一个开源 JSON 解析器，用于 Linux、Windows 和 macOS。
这些示例使用 jq 简化日志解析。
计算唯一消息数
以下示例按频率排序显示给定日志文件中的前 10 个唯一消息值：
jq -r ".msg" /var/log/mongodb/mongod.log | sort | uniq -c | sort -rn | head -10
监控连接
远程客户端连接显示在属性对象中 "remote" 键下的日志中。以下内容对日志文件过程中的所有唯一连接进行计数，并按出现次数降序排列这些连接：
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | sort | uniq -c | sort -r
请注意，该命令将来自同一 IP 地址但通过不同端口的连接视为不同的连接。您可以将输出限制为仅考虑 IP 地址，并进行以下更改：
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | awk -F':' '{print $1}' | sort | uniq -c | sort -r
分析驱动程序连接
以下示例统计了所有远程 MongoDB 驱动程序连接，并按出现次数降序显示每种驱动程序类型和版本：
jq -cr '.attr.doc.driver' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
分析客户端类型
以下示例分析远程 MongoDB 驱动程序连接和客户端应用程序（包括 mongosh）所报告的客户端数据，并按照频率排序打印连接的每个唯一操作系统类型的总计数。
jq -r '.attr.doc.os.type' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
此日志字段中报告的字符串 "Darwin" 代表 macOS 客户端。
分析慢查询
启用慢操作日志记录后，以下内容仅返回用时超过 2000 毫秒的慢操作，以供进一步分析：
jq 'select(.attr.workingMillis>=2000)' /var/log/mongodb/mongod.log
查阅 jq 文档，了解本示例所示 jq 过滤器的更多信息。
按组件筛选
日志组件（JSON 日志输出格式中的第三个字段）表示特定日志消息所属的一般类别。在解析相关事件的日志消息时，按组件过滤通常是一个很好的切入点。
以下示例仅打印组件类型 REPL 的日志消息：
jq 'select(.c=="REPL")' /var/log/mongodb/mongod.log
以下示例打印除组件类型 REPL 之外的所有日志消息：
jq 'select(.c!="REPL")' /var/log/mongodb/mongod.log
以下示例打印组件类型 REPL 或 STORAGE 的日志消息：
jq 'select( .c as $c | ["REPL", "STORAGE"] | index($c) )' /var/log/mongodb/mongod.log
查阅 jq 文档，了解本示例所示 jq 过滤器的更多信息。
按已知日志 ID 筛选
日志 ID（JSON 日志输出格式中的第五个字段）映射到特定的日志事件，能在连续的 MongoDB 版本中保持稳定。
例如，以下两个日志事件显示客户端连接和之后的断开连接：
{"t":{"$date":"2020-06-01T13:06:59.027-0500"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener", "svc": "R", "msg":"connection accepted from {session_remote} #{session_id} ({connectionCount}{word} now open)", "attr":{"session_remote":"127.0.0.1:61298", "session_id":164,"connectionCount":11,"word":" connections"}} {"t":{"$date":"2020-06-01T13:07:03.490-0500"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn157", "svc": "R", "msg":"end connection {remote} ({connectionCount}{word} now open)", "attr":{"remote":"127.0.0.1:61298","connectionCount":10,"word":" connections"}}
这两个条目的日志 ID 分别为 22943 和 22944。您可以使用以下 jq 语法筛选日志输出以仅显示这些日志 ID，从而有效地仅显示客户端连接活动：
jq 'select( .id as $id | [22943, 22944] | index($id) )' /var/log/mongodb/mongod.log
查阅 jq 文档，了解本示例所示 jq 过滤器的更多信息。
按日期范围筛选
可以通过筛选时间戳字段来进一步细化日志输出，将返回的日志条目限制为特定日期范围。例如，以下命令返回 2020 年 4 月 15 日发生的所有日志条目：
jq 'select(.t["$date"] >= "2020-04-15T00:00:00.000" and .t["$date"] <= "2020-04-15T23:59:59.999")' /var/log/mongodb/mongod.log
此语法包含完整时间戳（包括毫秒但不包括时差）。
按日期范围筛选可以与上述任何示例结合，例如创建每周报告或年度摘要。以下语法扩展了之前的“监控连接”示例，将结果限制为 2020 年 5 月：
jq 'select(.t["$date"] >= "2020-05-01T00:00:00.000" and .t["$date"] <= "2020-05-31T23:59:59.999" and .attr.remote)' /var/log/mongodb/mongod.log
查阅 jq 文档，了解本示例所示 jq 过滤器的更多信息。
日志摄取服务
日志摄取服务是一种第三方产品，摄取和汇总日志文件（通常来自分布式系统集群），并在中央位置对这些数据进行持续分析。
JSON 日志格式有助于您更加灵活地使用日志摄取和分析服务。虽然纯文本日志通常需要某种转换才能适合与这些产品一起使用，但 JSON 文件通常可以开箱即用，具体取决于服务。此外，JSON 格式的日志在对这些服务执行过滤时提供了更多控制，因为键值结构具备仅导入感兴趣的字段而忽略其余字段的能力。
有关更多信息，请参阅所选第三方日志摄取服务的文档。
日志消息示例
以下示例以 JSON 输出格式显示日志消息。
为方便起见，这些日志信息以美观打印格式呈现。
启动警告
此示例显示启动警告：
{ "t": { "$date": "2020-05-20T19:17:06.188+00:00" }, "s": "W", "c": "CONTROL", "id": 22120, "ctx": "initandlisten", "svc": "R", "msg": "Access control is not enabled for the database. Read and write access to data and configuration is unrestricted", "tags": [ "startupWarnings" ] }
客户端连接
该示例显示一个包含客户端数据的客户端连接：
{ "t": { "$date": "2020-05-20T19:18:40.604+00:00" }, "s": "I", "c": "NETWORK", "id": 51800, "ctx": "conn281", "svc": "R", "msg": "client metadata", "attr": { "remote": "192.168.14.15:37666", "client": "conn281", "doc": { "application": { "name": "MongoDB Shell" }, "driver": { "name": "MongoDB Internal Client", "version": "4.4.0" }, "os": { "type": "Linux", "name": "CentOS Linux release 8.0.1905 (Core) ", "architecture": "x86_64", "version": "Kernel 4.18.0-80.11.2.el8_0.x86_64" } } } }
慢操作
从 MongoDB 8.0 开始，慢速操作的记录基于 MongoDB 在该操作上花费的时间，而不是操作的总延迟。
您可以使用慢速操作日志中的指标来确定操作在其生命周期中花费的时间，这有助于确定可能的性能改进。
在以下示例日志消息中：
这些指标显示了执行查询时等待资源所花费的时间：
queues.execution.totalTimeQueuedMicrostimeAcquiringMicros
workingMillis是 MongoDB 处理该操作所花费的时间。durationMillis是操作的总延迟。
{ "t":{ "$date":"2024-06-01T13:24:10.034+00:00" }, "s":"I", "c":"COMMAND", "id":51803, "ctx":"conn3", "msg":"Slow query", "attr":{ "type":"command", "isFromUserConnection":true, "ns":"db.coll", "collectionType":"normal", "appName":"MongoDB Shell", "command":{ "find":"coll", "filter":{ "b":-1 }, "sort":{ "splitPoint":1 }, "readConcern":{ }, "$db":"db" }, "planSummary":"COLLSCAN", "planningTimeMicros":87, "keysExamined":0, "docsExamined":20889, "hasSortStage":true, "nBatches":1, "cursorExhausted":true, "numYields":164, "nreturned":99, "planCacheShapeHash":"9C05019A", "planCacheKey":"C41063D6", "queryFramework":"classic", "reslen":96, "locks":{ "ReplicationStateTransition":{ "acquireCount":{ "w":3 } }, "Global":{ "acquireCount":{ "r":327, "w":1 } }, "Database":{ "acquireCount":{ "r":1 }, "acquireWaitCount":{ "r":1 }, "timeAcquiringMicros":{ "r":2814 } }, "Collection":{ "acquireCount":{ "w":1 } } }, "flowControl":{ "acquireCount":1, "acquireWaitCount":1, "timeAcquiringMicros":8387 }, "readConcern":{ "level":"local", "provenance":"implicitDefault" }, "storage":{ }, "cpuNanos":20987385, "remote":"127.0.0.1:47150", "protocol":"op_msg", "queues":{ "ingress":{ "admissions":7, "totalTimeQueuedMicros":0 }, "execution":{ "admissions":328, "totalTimeQueuedMicros":2109 } }, "workingMillis":89, "durationMillis":101 } }
从 MongoDB 8.0 开始，预先存在的 queryHash 字段被重命名为 planCacheShapeHash。如果正在使用早期版本的 MongoDB，您将看到 queryHash 而不是 planCacheShapeHash。
转义
此示例演示了字符转义，如属性对象的 setName 字段所示：
{ "t": { "$date": "2020-05-20T19:11:09.268+00:00" }, "s": "I", "c": "REPL", "id": 21752, "ctx": "ReplCoord-0", "svc": "R", "msg": "Scheduling remote command request", "attr": { "context": "vote request", "request": "RemoteCommand 229 -- target:localhost:27003 db:admin cmd:{ replSetRequestVotes: 1, setName: \"my-replica-name\", dryRun: true, term: 3, candidateIndex: 0, configVersion: 2, configTerm: 3, lastAppliedOpTime: { ts: Timestamp(1589915409, 1), t: 3 } }" } }
查看
从 MongoDB 5.0 开始，对视图的慢查询的日志信息包括一个包含视图详细信息的 resolvedViews 字段：
"resolvedViews": [ { "viewNamespace": <String>, // namespace and view name "dependencyChain": <Array of strings>, // view name and collection "resolvedPipeline": <Array of documents> // aggregation pipeline for view } ]
以下示例使用 test 数据库并创建名为 myView 的视图，该视图按 firstName 字段对 myCollection 中的文档排序：
use test db.createView( "myView", "myCollection", [ { $sort: { "firstName" : 1 } } ] )
假设在 myView 上运行一个慢查询。以下示例日志消息包含针对 myView 的 resolvedViews 字段：
{ "t": { "$date": "2021-09-30T17:53:54.646+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn249", "svc": "R", "msg": "Slow query", "attr": { "type": "command", "ns": "test.myView", "appName": "MongoDB Shell", "command": { "find": "myView", "filter": {}, "lsid": { "id": { "$uuid": "ad176471-60e5-4e82-b977-156a9970d30f" } }, "$db": "test" }, "planSummary":"COLLSCAN", "resolvedViews": [ { "viewNamespace": "test.myView", "dependencyChain": [ "myView", "myCollection" ], "resolvedPipeline": [ { "$sort": { "firstName": 1 } } ] } ], "keysExamined": 0, "docsExamined": 1, "hasSortStage": true, "cursorExhausted": true, "numYields": 0, "nreturned": 1, "planCacheShapeHash": "3344645B", "planCacheKey": "1D3DE690", "queryFramework": "classic" "reslen": 134, "locks": { "ParallelBatchWriterMode": { "acquireCount": { "r": 1 } }, "ReplicationStateTransition": { "acquireCount": { "w": 1 } }, "Global": { "acquireCount": { "r": 4 } }, "Database": { "acquireCount": {"r": 1 } }, "Collection": { "acquireCount": { "r": 1 } }, "Mutex": { "acquireCount": { "r": 4 } } }, "storage": {}, "remote": "127.0.0.1:34868", "protocol": "op_msg", "workingMillis": 0, "durationMillis": 0 } } }
从 MongoDB 8.0 开始，预先存在的 queryHash 字段被重命名为 planCacheShapeHash。如果正在使用早期版本的 MongoDB，您将看到 queryHash 而不是 planCacheShapeHash。
授权
从 MongoDB 5.0 开始，慢速查询的日志信息会包含一个 system.profile.authorization 部分。这些指标有助于确定请求是否由于用户授权缓存争用而延迟。
"authorization": { "startedUserCacheAcquisitionAttempts": 1, "completedUserCacheAcquisitionAttempts": 1, "userCacheWaitTimeMicros": 508 },
会话工作流日志消息
从 MongoDB 6.3 开始，如果发生以下情况，日志中就会添加一条信息：发送操作响应的时间超过 slowms 阈值选项。
该消息称为会话工作流日志消息，包含在数据库会话中执行操作的各种时间。
会话工作流日志消息示例：
{ "t": { "$date": "2022-12-14T17:22:44.233+00:00" }, "s": "I", "c": "EXECUTOR", "id": 6983000, "ctx": "conn1", "svc": "R", "msg": "Slow network response send time", "attr": { "elapsed": { "totalMillis": 109, "activeMillis": 30, "receiveWorkMillis": 2, "processWorkMillis": 10, "sendResponseMillis": 22, "yieldMillis": 15, "finalizeMillis": 30 } } }
时间以毫秒为单位。
如果 sendResponseMillis 超过 slowms 阈值选项，则会向日志添加一条会话工作流消息。
字段 | 说明 |
|---|---|
| 会话中执行操作的总时间，包括等待接收信息的时间。 |
| 从接收消息到完成与该消息关联的操作之间的时间。这个时间包括发送响应和执行任何清理。 |
| 通过网络接收操作信息的时间。 |
| 处理操作和创建响应的时间。 |
| 发送响应的时间。 |
| 释放工作线程和再次使用该线程之间的时间。 |
| 结束和关闭会话工作流的时间。 |
连接获取到传输日志消息
从 MongoDB 6.3 开始，如果一个操作从获取服务器连接到通过网络向服务器发送字节的等待时间超过 1 毫秒，则日志中就会添加一条消息。
默认情况下，消息在 "I" 信息级别记录，最多每秒一次，以避免日志消息过多。如果必须获取每条日志消息，请将日志级别更改为调试。
如果操作等待时间超过 1 毫秒，并且上一秒内将消息记录在信息级别，则将在调试级别记录下一条消息。否则，将在信息级别记录下一条消息。
示例日志消息：
{ "t": { "$date":"2023-01-31T15:22:29.473+00:00" }, "s": "I", "c": "NETWORK", "id": 6496702, "ctx": "ReplicaSetMonitor-TaskExecutor", "svc": "R", "msg": "Acquired connection for remote operation and completed writing to wire", "attr": { "durationMicros": 1683 } }
下表描述 attr 中的 durationMicros 字段。
字段 | 说明 |
|---|---|
| 操作在获取服务器连接和写入字节以通过网络发送到服务器之间等待的总时间（以微秒为单位）。 |
缓存刷新时间
从 MongoDB 6.1 开始，慢查询的日志消息包括以下缓存刷新时间字段：
catalogCacheDatabaseLookupDurationMilliscatalogCacheCollectionLookupDurationMillisdatabaseVersionRefreshDurationMillisshardVersionRefreshMillis
从 MongoDB 7.0 开始，针对慢速查询的日志信息还包括 catalogCacheIndexLookupDurationMillis 字段，该字段表示此操作从索引缓存中获取信息所花费的时间。此版本还将 shardVersionRefreshMillis 字段重命名为 placementVersionRefreshMillis。
以下示例包括：
catalogCacheDatabaseLookupDurationMilliscatalogCacheCollectionLookupDurationMilliscatalogCacheIndexLookupDurationMillis
{ "t": { "$date": "2023-03-17T09:47:55.929+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn14", "svc": "R", "msg": "Slow query", "attr": { "type": "command", "ns": "db.coll", "appName": "MongoDB Shell", "command": { "insert": "coll", "ordered": true, "lsid": { "id": { "$uuid": "5d50b19c-8559-420a-a122-8834e012274a" } }, "$clusterTime": { "clusterTime": { "$timestamp": { "t": 1679046398, "i": 8 } }, "signature": { "hash": { "$binary": { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "0" } }, "keyId": 0 } }, "$db": "db" }, "catalogCacheDatabaseLookupDurationMillis": 19, "catalogCacheCollectionLookupDurationMillis": 68, "catalogCacheIndexLookupDurationMillis": 16026, "nShards": 1, "ninserted": 1, "numYields": 232, "reslen": 96, "readConcern": { "level": "local", "provenance": "implicitDefault", }, "cpuNanos": 29640339, "remote": "127.0.0.1:48510", "protocol": "op_msg", "remoteOpWaitMillis": 4078, "workingMillis": 20334, "durationMillis": 20334 } }
Linux 系统日志限制
在 Linux 系统中，消息遵循 Linux 配置文件 /etc/systemd/journald.conf 中定义的规则。默认情况下，日志消息突发量限制为 30 秒内 1000 条消息。要查看更多消息，请提高 /etc/systemd/journald.conf 中的 RateLimitBurst参数。
下载日志
您可以使用 MongoDB Atlas 下载压缩文件，其中包含数据库部署中选定主机名或进程的日志。 要了解更多信息，请参阅查看和下载 MongoDB 日志。