文档菜单
文档首页
/
MongoDB 手册
/

日志消息

本页内容

  • 概述
  • 结构化日志记录
  • 日志消息字段类型
  • 详细程度级别
  • 日志编辑
  • 解析结构化日志消息
  • 日志消息示例
  • Linux 系统日志限制
  • 下载您的日志

作为正常操作的一部分,MongoDB维护一个运行日志,包括如下条目:传入连接、运行的命令以及遇到的问题。通常,日志消息对于诊断问题、监控您的部署和调整性能非常有用。

要获取您的日志消息,您可以使用以下任何一种方法:

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 格式,包括发送到

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
对象
一个或多个额外的日志属性的关键字-值对。如果没有额外的属性,则省略attr对象。
如果日志消息不包含任何额外属性,则
attr对象被省略。
属性值可以根据消息的键名称在msg消息体中进行引用。根据需要,属性将根据JSON规范进行转义
如果需要,属性将根据JSON规范进行转义
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的日志消息可以输出到文件syslogstdout(标准输出)。

要配置日志输出目标,请使用以下设置之一,可以在配置文件或命令行中

配置文件
命令行

如果没有指定文件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

调试,用于详细程度 > 0

MongoDB指示特定的调试详细程度级别。例如,如果详细程度级别为2,MongoDB指示D2

在之前的版本中,MongoDB日志消息使用D表示所有调试详细程度级别。

您可以通过指定各个组件的详细程度级别来决定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设置。

命令

与数据库命令相关的消息,例如 数据库命令,如 count。要指定 命令 组件的日志级别,请使用 systemLog.component.command.verbosity 设置。

控制

与控制活动相关的消息,例如初始化。要指定 控制 组件的日志级别,请使用 systemLog.component.control.verbosity 设置。

选举

与副本集选举相关的消息。要指定 ELECTION 组件的日志级别,设置 systemLog.component.replication.election.verbosity 参数。

REPLELECTION 的父组件。如果未设置 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 参数。

REPLINITSYNC 的父组件。如果未设置 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 设置。

STORAGERECOVERY 的父组件。如果未设置 systemLog.component.storage.recovery.verbosity,MongoDB 将使用 STORAGE 的详细程度级别为 RECOVERY 组件。

REPL

与副本集相关的消息,例如初始同步、心跳、稳定状态复制和回滚。 [2] 要指定 REPL 组件的日志级别,设置 systemLog.component.replication.verbosity 参数。

REPLELECTIONINITSYNCREPL_HBROLLBACK 组件的父组件。

REPL_HB

与副本集心跳相关的特定消息。要指定 REPL_HB 组件的日志级别,设置 systemLog.component.replication.heartbeats.verbosity 参数。

REPLREPL_HB 的父组件。如果未设置 systemLog.component.replication.heartbeats.verbosity,MongoDB 将使用 REPL 的详细程度级别为 REPL_HB 组件。

ROLLBACK

回滚 操作相关的消息。要指定 ROLLBACK 组件的日志级别,请设置 systemLog.component.replication.rollback.verbosity 参数。

REPLROLLBACK 的父组件。如果未设置 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设置。

-

与未命名的组件相关的消息。未命名的组件的默认日志级别由systemLog.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.verbositysystemLog.component.<name>.verbosity 设置,logComponentVerbosity 参数,或 db.setLogLevel() 方法。[2]

要配置所有 组件 的默认日志级别,请使用 systemLog.verbosity 设置。要配置特定组件的级别,请使用 systemLog.component.<name>.verbosity 设置。

例如,以下配置将 systemLog.verbosity 设置为 1systemLog.component.query.verbosity 设置为 2systemLog.component.storage.verbosity 设置为 2,以及 systemLog.component.storage.journal.verbosity 设置为 1

systemLog:
verbosity: 1
component:
query:
verbosity: 2
storage:
verbosity: 2
journal:
verbosity: 1

您可以在 配置文件 中或在您的 mongodmongos 实例的命令行上设置这些值。

在配置中未明确指定的所有组件的详细程度级别为 -1,表示如果它们有父组件,则继承父组件的详细程度级别,如果没有父组件,则继承全局详细程度级别(systemLog.verbosity)。

要设置 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() 方法更新单个组件日志级别。对于组件,您可以将详细级别指定为 05,或者您可以将 -1 指定为继承父级的详细级别。例如,以下将 systemLog.component.query.verbosity 设置为其父级详细级别(即默认详细级别)

db.setLogLevel(-1, "query")

您可以从 mongosh. 设置此值。

[2](1, 2, 3, 4, 5) 副本集的次要成员现在记录应用时间超过慢操作阈值的操作日志条目。
  • 这些慢操作日志条目记录在诊断日志中。
  • 它们在REPL组件下记录,文本为已应用操作: <oplog entry> 耗时 <num>ms
  • 这些日志不依赖于日志级别(无论是在系统级别还是组件级别)。
  • 这些日志不依赖于分析级别。
  • slowOpSampleRate的影响。
分析器不捕获慢操作日志条目。

如果客户端操作(如查询)的持续时间超过慢操作阈值,或者当日志详细程度为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字段,该字段包含操作在相应队列中花费的总累计时间,以微秒为单位。

在版本5.0.

从MongoDB 5.0开始,您可以使用remoteOpWaitMillis日志字段来获取从分片获取结果的等待时间(以毫秒为单位)。

remoteOpWaitMillis只有在以下情况下才会记录:

要确定合并操作或分片问题是否导致慢查询,请比较日志中的workingMillisremoteOpWaitMillis时间字段。workingMillis是查询完成所需的总时间。具体来说

  • 如果 workingMillis 比略长于 remoteOpWaitMillis,则大多数时间都花费在等待分片响应上。例如,workingMillis 为 17,而 remoteOpWaitMillis 为 15。

  • 如果 workingMillis 比显著长于 remoteOpWaitMillis,则大多数时间都花费在合并操作上。例如,workingMillis 为 100,而 remoteOpWaitMillis 为 15。

当使用 可查询加密 时,对加密集合的 CRUD 操作将不会记录在慢查询日志中。有关详细信息,请参阅 可查询加密编辑。

仅适用于 MongoDB 企业版

运行带有 mongodmongosredactClientLogData 参数可以在记录之前删除与特定日志事件相关的任何消息,仅保留与事件相关的元数据、源文件或行号。使用 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

以下示例打印组件类型为REPLSTORAGE的日志消息。

jq 'select( .c as $c | ["REPL", "STORAGE"] | index($c) )' /var/log/mongodb/mongod.log

有关本例中显示的jq过滤器的更多信息,请参考jq文档

日志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分别是2294322944。然后,您可以使用以下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上运行了一个慢查询。以下示例日志消息包含一个针对myViewresolvedViews字段

{
"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系统中,消息受到Linux配置文件/etc/systemd/journald.conf中定义的规则约束。默认情况下,日志消息突发量限制在30秒内的1000条消息。要查看更多消息,请增加RateLimitBurst参数,该参数位于/etc/systemd/journald.conf中。

您可以使用MongoDB Atlas下载一个包含所选主机名或数据库部署中进程的日志的压缩文件。有关更多信息,请参阅查看和下载MongoDB日志。

返回

术语表