日志消息
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", "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", "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 "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 格式的日志消息时间戳。有关示例,请参阅时间戳。 |
| 字符串 | |
| 字符串 | |
| 整型 | |
| 字符串 | 产生日志语句的线程的名称。 |
| 字符串 | |
| 对象 | |
| 字符串数组 | 表示适用于日志语句的任何标签的字符串。例如: |
| 对象 | |
| 对象 |
转义
根据宽松扩展 JSON v2.0 规范,消息和属性字段会根据需要对控制字符进行转义:
所代表的字符 | 转义序列 |
---|---|
引号 ( |
|
Backslash ( |
|
退格 ( |
|
进纸 ( |
|
换行符 ( |
|
回车 ( |
|
Horizontal tab ( |
|
上面未列出的控制字符使用 \uXXXX
进行转义,其中 "XXXX" 是十六进制的 unicode 代码点。具有无效 UTF-8 编码的字节将替换为 \ufffd
表示的 unicode 替换字符。
消息转义的示例请参阅示例部分。
截断
任何超过 maxLogSizeKB
定义的最大大小(默认值:10 KB)的属性都将被截断。截断的属性会省略超出配置限制的日志数据,但保留条目的 JSON 格式,以确保条目仍可解析。
下面的示例是一个带有截断属性的日志条目:
{"t":{"$date":"2020-05-19T18:12:05.702+00:00"},"s":"I", "c":"SHARDING", "id":22104, "ctx":"conn33", "msg":"Received splitChunk request","attr":{"request":{"splitChunk":"config.system.sessions", "from":"production-shard1","keyPattern":{"_id":1},"epoch":{"$oid":"5ec42172996456771753a59e"}, "shardVersion":[{"$timestamp":{"t":1,"i":0}},{"$oid":"5ec42172996456771753a59e"}],"min":{"_id":{"$minKey":1}}, "max":{"_id":{"$maxKey":1}},"splitKeys":[{"_id":{"id":{"$uuid":"00400000-0000-0000-0000-000000000000"}}}, {"_id":{"id":{"$uuid":"00800000-0000-0000-0000-000000000000"}}}, ... {"_id":{"id":{"$uuid":"26c00000-0000-0000-0000-000000000000"}}},{"_id":{}}]}}, "truncated":{"request":{"splitKeys":{"155":{"_id":{"id":{"type":"binData","size":21}}}}}}, "size":{"request":46328}}
在这个示例中,request
属性被截断,截断是由其子字节 _id
触发的(导致该属性超过 maxLogSizeKB
),带子字节的特定示例打印结果中没有数据为 {"_id":{}}
。然后省略 request
属性的其余部分。
包含一个或多个截断属性的日志条目有一个 truncated
对象,该对象为日志条目中的每个截断属性提供以下信息:
被截断的属性
触发截断的该属性的特定子对象(如果适用)。
截断字段的数据
type
截断字段的
size
具有截断属性的日志条目还可能在条目末尾包含一个附加的 size
字段,该字段指示截断之前属性的原始大小,在本例中为 46328
或大约 46KB。仅当最终 size
字段与 truncated
对象中的 size
字段不同时(即属性的总对象大小与截断子对象的大小不同),才会显示最终字段,如上面的示例中的情况。
填充
输出到文件或系统日志日志目的地时,会在严重性、上下文和 id 字段之后添加填充,从而提高使用固定宽度字体查看时的可读性。
以下 MongoDB 日志文件摘录演示了这种填充:
{"t":{"$date":"2020-05-18T20:18:12.724+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main","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","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","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","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","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","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", "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", "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", "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
设置。
WT
5.3 版本中的新增功能。
与 WiredTiger 存储引擎相关的消息。要指定
WT
组件的日志级别,请使用systemLog.component.storage.wt.verbosity
设置。
WTBACKUP
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的备份操作相关的消息。要指定
WTBACKUP
组件的日志级别,请使用systemLog.component.storage.wt.wtBackup.verbosity
设置。
WTCHKPT
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的检查点操作相关的消息。要指定
WTCHKPT
组件的日志级别,请使用systemLog.component.storage.wt.wtCheckpoint.verbosity
设置。
WTCMPCT
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的压缩操作相关的消息。要指定
WTCMPCT
组件的日志级别,请使用systemLog.component.storage.wt.wtCompact.verbosity
设置。
WTEVICT
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的驱逐操作相关的消息。要指定
WTEVICT
组件的日志级别,请使用systemLog.component.storage.wt.wtEviction.verbosity
设置。
WTHS
5.3 版本中的新增功能。
与 WiredTiger 存储引擎的历史存储相关的消息。要指定
WTHS
组件的日志级别,请使用systemLog.component.storage.wt.wtHS.verbosity
设置。
WTRECOV
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的恢复操作相关的消息。要指定
WTRECOV
组件的日志级别,请使用systemLog.component.storage.wt.wtRecovery.verbosity
设置。
WTRTS
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的回滚到稳定 (RTS) 操作相关的消息。要指定
WTRTS
组件的日志级别,请使用systemLog.component.storage.wt.wtRTS.verbosity
设置。
WTSLVG
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的抢救操作相关的消息。要指定
WTSLVG
组件的日志级别,请使用systemLog.component.storage.wt.wtSalvage.verbosity
设置。
WTTS
5.3 版本中的新增功能。
与 WiredTiger 存储引擎使用的时间戳相关的消息。要指定
WTTS
组件的日志级别,请使用systemLog.component.storage.wt.wtTimestamp.verbosity
设置。
WTTXN
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的事务相关的消息。要指定
WTTXN
组件的日志级别,请使用systemLog.component.storage.wt.wtTransaction.verbosity
设置。
WTVRFY
5.3 版本中的新增功能。
与 WiredTiger 存储引擎执行的验证操作相关的消息。要指定
WTVRFY
组件的日志级别,请使用systemLog.component.storage.wt.wtVerify.verbosity
设置。
WTWRTLOG
5.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","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","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 日志消息)包括:
从 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 复制到副本集从节点。
等待分片登录到remoteOpWaitMillis
字段的时间
版本 5.0 中的新增功能。
从 MongoDB 5.0 开始,可以使用 remoteOpWaitMillis
日志字段来获取分片结果的等待时间(以毫秒为单位)。
remoteOpWaitMillis
仅记录:
要确定合并操作或分片问题是否导致查询缓慢,请比较日志中的 durationMillis
和 remoteOpWaitMillis
时间字段。durationMillis
是查询完成所需的总时间。具体而言:
如果
durationMillis
比remoteOpWaitMillis
稍长,则大部分时间都花在等待分片响应上。例如,durationMillis
为 17,remoteOpWaitMillis
为 15。如果
durationMillis
明显长于remoteOpWaitMillis
,则大部分时间都花在执行合并上。例如,durationMillis
为 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.durationMillis>=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","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","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", "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", "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" } } } }
慢操作
此示例显示一条慢速操作消息:
{ "t": { "$date": "2023-05-24T13:46:27.853+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn3", "msg": "Slow query", "attr": { "type": "command", "ns": "db.coll", "appName": "MongoDB Shell", "command": { "find": "coll", "filter": { "b": -1 }, "lsid": { "id": { "$uuid": "5d50b19c-8559-420a-a122-8834e012274a" } }, "$db": "db" }, "planSummary": "COLLSCAN", "planningTimeMicros": 228, "keysExamined": 0, "docsExamined": 232922, "fromPlanCache": true, "nBatches": 1, "cursorExhausted": true, "numYields": 232, "nreturned": 0, "queryHash": "9C05019A", "planCacheKey": "C41063D6", "queryFramework": "sbe", "reslen": 96, "locks": { "FeatureCompatibilityVersion": { "acquireCount": { "r": 233 } }, "Global": { "acquireCount": { "r": 233 } } }, "storage": {}, "cpuNanos": 111410254, "remote": "127.0.0.1:47150", "protocol": "op_msg", "durationMillis": 111 } }
转义
此示例演示了字符转义,如属性对象的 setName
字段所示:
{ "t": { "$date": "2020-05-20T19:11:09.268+00:00" }, "s": "I", "c": "REPL", "id": 21752, "ctx": "ReplCoord-0", "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", "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, "queryHash": "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", "durationMillis": 0 } } }
授权
从 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", "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", "msg": "Acquired connection for remote operation and completed writing to wire", "attr": { "durationMicros": 1683 } }
下表描述 attr
中的 durationMicros
字段。
字段 | 说明 |
---|---|
| 操作在获取服务器连接和写入字节以通过网络发送到服务器之间等待的总时间(以微秒为单位)。 |
缓存刷新时间
从 MongoDB 6.1 开始,慢查询的日志消息包括以下缓存刷新时间字段:
catalogCacheDatabaseLookupDurationMillis
catalogCacheCollectionLookupDurationMillis
databaseVersionRefreshDurationMillis
shardVersionRefreshMillis
从 MongoDB 7.0 开始,针对慢速查询的日志信息还包括 catalogCacheIndexLookupDurationMillis
字段,该字段表示此操作从索引缓存中获取信息所花费的时间。此版本还将 shardVersionRefreshMillis
字段重命名为 placementVersionRefreshMillis
。
以下示例包括:
catalogCacheDatabaseLookupDurationMillis
catalogCacheCollectionLookupDurationMillis
catalogCacheIndexLookupDurationMillis
{ "t": { "$date": "2023-03-17T09:47:55.929+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn14", "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, "durationMillis": 20334 } }
Linux 系统日志限制
在 Linux 系统中,消息遵循 Linux 配置文件 /etc/systemd/journald.conf
中定义的规则。默认情况下,日志消息突发量限制为 30 秒内 1000 条消息。要查看更多消息,请提高 /etc/systemd/journald.conf
中的 RateLimitBurst
参数。
下载日志
您可以使用 MongoDB Atlas 下载压缩文件,其中包含数据库部署中选定主机名或进程的日志。 要了解更多信息,请参阅查看和下载 MongoDB 日志。