日志消息
概述
作为正常操作的一部分,MongoDB维护一个运行日志,包括如下条目:传入连接、运行的命令以及遇到的问题。通常,日志消息对于诊断问题、监控您的部署和调整性能非常有用。
要获取您的日志消息,您可以使用以下任何一种方法:
在您配置的日志目标中查看日志.
运行
getLog
命令。通过MongoDB Atlas下载日志。要了解更多信息,请参阅下载您的日志。
结构化日志
mongod
/ mongos
实例以结构化的JSON格式输出所有日志消息。日志条目以一系列键值对的形式写入,其中每个键指示日志消息的字段类型,例如"severity",每个对应的值记录该字段类型的关联日志信息,例如"informational"。之前,日志条目以纯文本形式输出。
示例
以下是在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 格式,包括发送到
日志文件
系统日志
标准输出(标准输出) 日志目的地
从 getLog
命令输出的内容也是 JSON 格式。
每个日志条目都以一个自包含的 JSON 对象的形式输出,该对象遵循 Relaxed Extended 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) }
字段描述
字段名称 | 类型 | 描述 |
---|---|---|
t | 日期时间 | 日志消息的时间戳,ISO-8601 格式。例如,请参见 时间戳。 |
s | 字符串 | 日志消息的简短严重程度代码。例如,请参见 严重程度。 |
c | 字符串 | 日志消息的完整组件字符串。例如,请参见 组件。 |
id | 整数 | 日志语句的唯一标识符。例如,请参见 按已知日志 ID 过滤。 |
ctx | 字符串 | 导致日志语句的线程名称。 |
svc | 字符串 | 在哪个服务上下文中创建日志语句的名称。如果是“shard”,则为 S ,如果是“router”,则为R ,如果是“unknown”或“none”,则为- 。 |
msg | 字符串 | 从服务器或驱动器传递的日志输出消息。如果需要,根据JSON规范对消息进行转义。 |
attr | 对象 | |
tags | 字符串数组 | 表示适用于日志语句的任何标签的字符串。例如, ["startupWarnings"] 。 |
truncated | 对象 | 如果适用,关于日志消息截断的信息。只有当日志条目包含至少一个截断的 attr 属性时才包括。 |
size | 对象 | 如果日志条目已被截断,则原始日志条目的大小。只有当日志条目包含至少一个截断的 attr 属性时才包括。 |
转义
消息和属性字段将根据Relaxed Extended JSON v2.0规范对控制字符进行必要的转义。
表示的字符 | 转义序列 |
---|---|
引号( " ) | \" |
反斜杠( \ ) | \\ |
退格( 0x08 ) | \b |
换页( 0x0C ) | \f |
换行( 0x0A ) | \n |
回车( 0x0D ) | \r |
水平制表符( 0x09 ) | \t |
未在上列中列出的控制字符使用\uXXXX
进行转义,其中"XXXX"是十六进制的unicode代码点。无效的UTF-8编码的字节将被表示为unicode替换字符\ufffd
。
在示例部分中提供了一个消息转义示例。
截断
已更改在版本7.3.
任何超出使用 maxLogSizeKB
(默认:10 KB)定义的最大大小的属性都将被截断。截断的属性将省略超出配置限制的日志数据,但保留条目的JSON格式,以确保条目仍然可解析。
例如,以下JSON对象表示一个包含5000个元素的$in
字段且未进行截断的command
属性。
注意
示例日志条目已重新格式化以便阅读。
{ "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" } }
在此示例中,由于包含后续元素,command
属性的大小将超过maxLogSizeKB
,因此将截断$in
数组至第376个元素。省略了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
对象,为日志条目中的每个截断属性提供以下信息
被截断的属性
如果适用,触发截断的该属性的具体子对象
截断字段的
data
类型触发截断的元素的字节
size
由于截断在每个子对象下省略的元素数量
带有截断属性的日志条目还可能在条目末尾包含一个额外的size
字段,该字段表示截断前的原始属性大小,在这种情况下为21692
或约22KB。此最终的size
字段仅在它与truncated
对象中的size
字段不同时显示,即如果属性的总对象大小与截断子对象的大小不同,如上面的示例所示。
填充
当输出到文件或syslog日志目的地时,会在严重性、上下文和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的日志消息可以输出到文件、syslog或stdout(标准输出)。
要配置日志输出目标,请使用以下设置之一,可以在配置文件或命令行中
- 配置文件
systemLog.destination
选项用于文件或syslog
- 命令行
如果没有指定文件或syslog,则所有日志输出都发送到stdout。
有关日志设置和选项的完整列表,请参阅
- 配置文件
- 命令行
注意
发送到stderr
(标准错误)的错误消息,例如,在没有使用文件或syslog日志目标的情况下启动时的致命错误或与错误配置的日志设置相关的消息,不受日志输出目标设置的影响,并以纯文本格式打印到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" } }
当记录到文件或syslog时,默认的时间戳格式为iso8601-local
。要修改时间戳格式,请使用--timeStampFormat
运行时选项或systemLog.timeStampFormat
设置。
请参阅按日期范围过滤,了解基于时间戳字段进行日志解析的示例。
注意
ctime
时间戳格式不再受支持。
[1] | 如果记录到syslog,则在记录消息时,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" } }
严重性级别从“致命”(最严重)到“调试”(最不严重)。
级别 | 描述 |
---|---|
F | 致命 |
E | 错误 |
W | 警告 |
I | 信息性,用于详细程度 0 |
D1 - D5 |
您可以通过指定各个组件的详细程度级别来决定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" } }
每个组件都可以通过其自己的详细程度过滤器单独配置。以下是可以用的组件:
命令
与数据库命令相关的消息,例如 数据库命令,如
count
。要指定命令
组件的日志级别,请使用systemLog.component.command.verbosity
设置。
控制
与控制活动相关的消息,例如初始化。要指定
控制
组件的日志级别,请使用systemLog.component.control.verbosity
设置。
选举
与副本集选举相关的消息。要指定
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
参数。
索引
与索引操作相关的消息,例如创建索引。要指定
索引
组件的日志级别,设置systemLog.component.index.verbosity
参数。
INITSYNC
与初始同步操作相关的消息。要指定
INITSYNC
组件的日志级别,设置systemLog.component.replication.initialSync.verbosity
参数。REPL
是INITSYNC
的父组件。如果未设置systemLog.component.replication.initialSync.verbosity
,MongoDB 使用REPL
的日志级别为INITSYNC
组件。
日志
与存储日志活动相关的消息。要指定
日志
组件的日志级别,请使用systemLog.component.storage.journal.verbosity
设置。存储
是日志
的父组件。如果未设置systemLog.component.storage.journal.verbosity
,MongoDB 将使用存储
的日志级别为日志
组件。
网络
与网络活动相关的消息,例如接受连接。要指定
网络
组件的日志级别,请设置systemLog.component.network.verbosity
参数。
查询
与查询相关的消息,包括查询规划器活动。要指定
查询
组件的日志级别,设置systemLog.component.query.verbosity
参数。
查询统计
与
$queryStats
操作相关的消息。要指定查询统计
组件的日志级别,设置systemLog.component.queryStats.verbosity
参数。
恢复
与存储恢复活动相关的消息。要指定
恢复
组件的日志级别,使用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
组件。
分片
与分片活动相关的消息,例如
mongos
的启动。要指定分片
组件的日志级别,请使用systemLog.component.sharding.verbosity
设置。
存储
与存储活动相关的消息,例如
fsync
命令涉及的进程。要指定存储
组件的日志级别,请使用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存储引擎使用的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
设置。
有关根据组件字段过滤的日志解析示例,请参阅按组件过滤。
客户端数据
MongoDB Drivers和客户端应用程序(包括mongosh
)在连接到服务器时能够发送标识信息。连接建立后,除非连接断开并重新建立,否则客户端不会再次发送标识信息。
此标识信息包含在日志条目的attributes
字段中。确切包含的信息因客户端而异。
以下是一个示例日志消息,其中包含了从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
参数
要设置 logComponentVerbosity
参数,传递一个包含要更改的详细级别的文档。
例如,以下设置 默认详细级别
为 1
,将 查询
设置为 2
,将 存储
设置为 2
,并将 存储.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) 副本集的次要成员现在记录应用时间超过慢操作阈值的操作日志条目。
|
记录慢操作
如果客户端操作(如查询)的持续时间超过慢操作阈值,或者当日志详细程度为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开始,慢操作日志消息和数据库分析器条目包含一个指定查询操作在纳秒级上花费的总CPU时间的cpuNanos
字段。该cpuNanos
字段仅在Linux系统上可用。
从MongoDB 7.0(以及6.0.13和5.0.24)开始,慢查询日志消息中的totalOplogSlotDurationMicros
显示了写操作从获得提交时间戳到实际提交存储引擎写入之间的时间。`mongod`支持并行写入。然而,它以任意顺序提交带提交时间戳的写操作。
示例
考虑以下带有提交时间戳的写入操作
带有Timestamp1的writeA
带有Timestamp2的writeB
带有Timestamp3的writeC
假设writeB首先在Timestamp2处提交。复制会暂停,直到writeA提交,因为复制需要writeA的带有Timestamp1的操作日志条目来将操作日志复制到次要副本集成员。
从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。
日志编辑
可查询加密日志编辑
企业日志编辑
仅适用于 MongoDB 企业版
运行带有 mongod
或 mongos
的 redactClientLogData
参数可以在记录之前删除与特定日志事件相关的任何消息,仅保留与事件相关的元数据、源文件或行号。使用 redactClientLogData
参数可以在不牺牲诊断细节的情况下,防止可能敏感的信息进入系统日志。
例如,以下操作将文档插入到一个未启用日志删除的 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日志格式在处理日志采集和分析服务时提供了更大的灵活性。与plaintext日志相比,这些产品通常需要某种形式的转换才能使用,而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.totalTimeQueuedMicros
timeAcquiringMicros
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阈值选项。
字段 | 描述 |
---|---|
totalMillis | 会话中执行操作的总时间,包括等待接收消息的时间。 |
activeMillis | 接收消息和完成与该消息相关的操作之间的时间。时间包括发送响应和执行任何清理。 |
receivedWorkMillis | 接收操作信息通过网络的时间。 |
processWorkMillis | 处理操作并创建响应的时间。 |
sendResponseMillis | 发送响应的时间。 |
yieldMillis | 释放工作线程和线程再次被使用之间的时间。 |
finalize | 结束和关闭会话工作流的时间。 |
连接获取到网络日志消息
从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
字段。
字段 | 描述 |
---|---|
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", "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 Syslog Limitations
在Linux系统中,消息受到Linux配置文件/etc/systemd/journald.conf
中定义的规则约束。默认情况下,日志消息突发量限制在30秒内的1000条消息。要查看更多消息,请增加RateLimitBurst
参数,该参数位于/etc/systemd/journald.conf
中。
下载您的日志
您可以使用MongoDB Atlas下载一个包含所选主机名或数据库部署中进程的日志的压缩文件。有关更多信息,请参阅查看和下载MongoDB日志。