MongoDB 日志消息

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)
}

字段说明：

{
  "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"
        }
}

{
  "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
  }
}

{"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 日志消息可以输出到文件、系统日志或 stdout（标准输出）。

要配置日志输出目的地，可在配置文件或命令行中使用以下设置

配置文件：

• 文件或系统日志的 systemLog.destination 选项

命令行：

• 针对文件，mongod 的 --logpath 选项

• 针对系统日志，mongod 的 --syslog 选项

• 针对文件，mongos 的 --logpath 选项

• 针对系统日志，mongos 的 --syslog 选项

不指定文件或系统日志会将所有日志输出发送到标准输出。

有关日志记录设置和选项的完整列表，请参阅：

配置文件：

• 系统日志选项列表

命令行：

• mongod 的日志选项列表

• mongos 的日志选项列表

时间戳

时间戳字段类型指示记录的事件发生的确切日期和时间。

{
  "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"
  }
}

When logging to file or to syslog [1], the default format for the timestamp is iso8601-local. To modify the timestamp format, use the --timeStampFormat runtime option or the systemLog.timeStampFormat setting.

请参阅按日期范围过滤，查看过滤时间戳字段的解析示例。

严重性

严重性字段类型表示与记录的事件关联的严重性级别。

{
  "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"
  }
}

严重性级别从“致命”（最严重）到“调试”（最不严重）：

You can specify the verbosity level of various components to determine the amount of Informational and Debug messages MongoDB outputs. Severity categories above these levels are always shown. [2] To set verbosity levels, see Configure Log Verbosity Levels.

组件

组件字段类型表示记录的事件所属的类别，例如网络或命令。

{
  "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"
  }
}

Each component is individually configurable through its own verbosity filter. The available components are as follows:

ACCESS

与访问控制（例如身份验证）相关的消息。要指定 ACCESS 组件的日志级别，请使用 systemLog.component.accessControl.verbosity 设置。

ASSERT

An assertion is triggered when an operation returns an error. The default verbosity level is 0. However, the verbosity setting must be at least 1 in order for operations that return errors to be included in the system logs. To specify the log level for ACCESS components, use the assert setting.

COMMAND

Messages related to database commands, such as count. To specify the log level for COMMAND components, use the systemLog.component.command.verbosity setting.

CONTROL

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

ELECTION

Messages related specifically to replica set elections. To specify the log level for ELECTION components, set the systemLog.component.replication.election.verbosity parameter.

REPL is the parent component of ELECTION. If systemLog.component.replication.election.verbosity is unset, MongoDB uses the REPL verbosity level for ELECTION components.

FTDC

与诊断数据收集机制相关的消息，例如服务器统计信息和状态消息。要指定 FTDC 组件的日志级别，请使用 systemLog.component.ftdc.verbosity 设置。

GEO

Messages related to the parsing of geospatial shapes, such as verifying the GeoJSON shapes. To specify the log level for GEO components, set the systemLog.component.geo.verbosity parameter.

INDEX

Messages related to indexing operations, such as creating indexes. To specify the log level for INDEX components, set the systemLog.component.index.verbosity parameter.

INITSYNC

Messages related to initial sync operation. To specify the log level for INITSYNC components, set the systemLog.component.replication.initialSync.verbosity parameter.

REPL is the parent component of INITSYNC. If systemLog.component.replication.initialSync.verbosity is unset, MongoDB uses the REPL verbosity level for INITSYNC components.

JOURNAL

与存储日志活动明确相关的消息。要指定 JOURNAL 组件的日志级别，请使用 systemLog.component.storage.journal.verbosity 设置。

STORAGE is the parent component of JOURNAL. If systemLog.component.storage.journal.verbosity is unset, MongoDB uses the STORAGE verbosity level for JOURNAL components.

NETWORK

Messages related to network activities, such as accepting connections. To specify the log level for NETWORK components, set the systemLog.component.network.verbosity parameter.

QUERY

Messages related to queries, including query planner activities. To specify the log level for QUERY components, set the systemLog.component.query.verbosity parameter.

QUERYSTATS

与$queryStats操作相关的消息。 要指定QUERYSTATS组件的日志级别，请设立systemLog.component.queryStats.verbosity参数。

RECOVERY

与存储恢复活动相关的消息。要指定 RECOVERY 组件的日志级别，请使用 systemLog.component.storage.recovery.verbosity 设置。

STORAGE is the parent component of RECOVERY. If systemLog.component.storage.recovery.verbosity is unset, MongoDB uses the STORAGE verbosity level for RECOVERY components.

REJECTED

8.0版本新增。

与被拒绝的查询操作相关的消息。

要指定 REJECTED 组件消息的日志级别，请设置 systemLog.component.query.rejected.verbosity 参数。

MongoDB 仅在详细程度设置为至少 2 时才记录 REJECTED 组件消息。

The parent component for REJECTED is QUERY.

REPL

Messages related to replica sets, such as initial sync, heartbeats, steady state replication, and rollback. [2] To specify the log level for REPL components, set the systemLog.component.replication.verbosity parameter.

REPL is the parent component of the ELECTION, INITSYNC, REPL_HB, and ROLLBACK components.

REPL_HB

Messages related specifically to replica set heartbeats. To specify the log level for REPL_HB components, set the systemLog.component.replication.heartbeats.verbosity parameter.

REPL is the parent component of REPL_HB. If systemLog.component.replication.heartbeats.verbosity is unset, MongoDB uses the REPL verbosity level for REPL_HB components.

ROLLBACK

Messages related to rollback operations. To specify the log level for ROLLBACK components, set the systemLog.component.replication.rollback.verbosity parameter.

REPL is the parent component of ROLLBACK. If systemLog.component.replication.rollback.verbosity is unset, MongoDB uses the REPL verbosity level for ROLLBACK components.

SHARDING

Messages related to sharding activities, such as the startup of the mongos. To specify the log level for SHARDING components, use the systemLog.component.sharding.verbosity setting.

SLOWPROG

8.3版本新增。

Messages related to slow in-progress queries. To specify the log level for SLOWPROG components, use the systemLog.component.command.slowInProgress.verbosity setting.

STORAGE

Messages related to storage activities, such as processes involved in the fsync command. To specify the log level for STORAGE components, use the systemLog.component.storage.verbosity setting.

STORAGE is the parent component of JOURNAL and RECOVERY.

TXN

Messages related to multi-document transactions. To specify the log level for TXN components, use the systemLog.component.transaction.verbosity setting.

WRITE

Messages related to write operations, such as update commands. To specify the log level for WRITE components, use the systemLog.component.write.verbosity setting.

WT

5.3版本新增。

Messages related to the WiredTiger storage engine. To specify the log level for WT components, use the systemLog.component.storage.wt.verbosity setting.

WTBACKUP

5.3版本新增。

Messages related to backup operations performed by the WiredTiger storage engine. To specify the log level for the WTBACKUP components, use the systemLog.component.storage.wt.wtBackup.verbosity setting.

WTCHKPT

5.3版本新增。

Messages related to checkpoint operations performed by the WiredTiger storage engine. To specify the log level for WTCHKPT components, use the systemLog.component.storage.wt.wtCheckpoint.verbosity setting.

WTCMPCT

5.3版本新增。

Messages related to compaction operations performed by the WiredTiger storage engine. To specify the log level for WTCMPCT components, use the systemLog.component.storage.wt.wtCompact.verbosity setting.

WTEVICT

5.3版本新增。

Messages related to eviction operations performed by the WiredTiger storage engine. To specify the log level for WTEVICT components, use the systemLog.component.storage.wt.wtEviction.verbosity setting.

WTHS

5.3版本新增。

Messages related to the history store of the WiredTiger storage engine. To specify the log level for WTHS components, use the systemLog.component.storage.wt.wtHS.verbosity setting.

WTRECOV

5.3版本新增。

Messages related to recovery operations performed by the WiredTiger storage engine. To specify the log level for WTRECOV components, use the systemLog.component.storage.wt.wtRecovery.verbosity setting.

WTRTS

5.3版本新增。

Messages related to rollback to stable (RTS) operations performed by the WiredTiger storage engine. To specify the log level for WTRTS components, use the systemLog.component.storage.wt.wtRTS.verbosity setting.

WTSLVG

5.3版本新增。

Messages related to salvage operations performed by the WiredTiger storage engine. To specify the log level for WTSLVG components, use the systemLog.component.storage.wt.wtSalvage.verbosity setting.

WTTS

5.3版本新增。

Messages related to timestamps used by the WiredTiger storage engine. To specify the log level for WTTS components, use the systemLog.component.storage.wt.wtTimestamp.verbosity setting.

WTTXN

5.3版本新增。

Messages related to transactions performed by the WiredTiger storage engine. To specify the log level for WTTXN components, use the systemLog.component.storage.wt.wtTransaction.verbosity setting.

WTVRFY

5.3版本新增。

Messages related to verification operations performed by the WiredTiger storage engine. To specify the log level for WTVRFY components, use the systemLog.component.storage.wt.wtVerify.verbosity setting.

WTWRTLOG

5.3版本新增。

Messages related to log write operations performed by the WiredTiger storage engine. To specify the log level for WTWRTLOG components, use the systemLog.component.storage.wt.wtWriteLog.verbosity setting.

-

与命名组件不相关的消息。在 systemLog.verbosity 设置中指定未命名组件的默认日志级别。systemLog.verbosity 设置是已命名和未命名组件的默认设置。

请参阅按组件过滤，了解按照组件字段过滤的日志解析示例。

客户端数据

MongoDB Drivers and client applications (including mongosh) can send identifying information at the time of connection to the server. After the connection is established, the client does not send the identifying information again unless the connection is dropped and reestablished.

该标识信息包含在日志条目的属性字段中。所包含的确切信息因客户端而异。

Below is a sample log message containing the client data document as transmitted from a mongosh connection. The client data is contained in the doc object in the attributes field:

{"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"}}}}

See the examples section for a pretty-printed example showing client data.

有关客户端信息和必填字段的完整说明，请参阅MongoDB 握手规范。

查看当前日志详细级别

要查看当前的详细级别，请使用 db.getLogComponents() 方法：

db.getLogComponents()

输出可能如下所示：

{
 "verbosity" : 0,
 "accessControl" : {
    "verbosity" : -1
 },
 "command" : {
    "verbosity" : -1
 },
 ...
 "storage" : {
    "verbosity" : -1,
    "recovery" : {
       "verbosity" : -1
    },
    "journal" : {
        "verbosity" : -1
    }
 },
 ...

The initial verbosity entry is the parent verbosity level for all components, while the individual named components that follow, such as accessControl, indicate the specific verbosity level for that component, overriding the global verbosity level for that particular component if set.

A value of -1, indicates that the component inherits the verbosity level of their parent, if they have one (as with recovery above, inheriting from storage), or the global verbosity level if they do not (as with command). Inheritance relationships for verbosity levels are indicated in the components section.

配置日志详细级别

You can configure the verbosity level using: the systemLog.verbosity and systemLog.component.<name>.verbosity settings, the logComponentVerbosity parameter, or the db.setLogLevel() method. [2]

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

db.adminCommand( {
   setParameter: 1,
   logComponentVerbosity: {
      verbosity: 1,
      query: {
         verbosity: 2
      },
      storage: {
         verbosity: 2,
         journal: {
            verbosity: 1
         }
      }
   }
} )

db.setLogLevel(-1, "query")

记录慢操作

Client operations (such as queries) appear in the log if their duration exceeds the slow operation threshold or when the log verbosity level is at least 1. [2] These log entries include the full command object associated with the operation.

用于读/写操作的分析器条目和诊断日志消息（即 mongod/mongos 日志消息）包括：

• planCacheShapeHash 帮助识别具有相同计划缓存查询结构的慢查询。

  从MongoDB 8.0 开始，现有的 queryHash字段将复制到名为 planCacheShapeHash 的新字段中。 如果您使用的是早期MongoDB版本，则只能看到 queryHash字段。 未来的MongoDB版本将删除已弃用的 queryHash字段，您需要改用 planCacheShapeHash字段。

• planCacheKey 更深入地了解慢查询的查询计划缓存。

等待分片登录到 remoteOpWaitMillis 字段的时间

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

remoteOpWaitMillis 仅记录：

• 如果您配置了慢速操作日志记录。

• 在该分片上或合并结果的 mongos 上。

要确定合并操作或分片问题是否导致查询缓慢，请比较日志中的 workingMillis 和 remoteOpWaitMillis 时间字段。workingMillis 是查询完成所需的总时间。具体而言：

• 如果 workingMillis 略长于 remoteOpWaitMillis，则等待分片响应花费的时间最长。例如，17 中的 workingMillis 和 15 中的 remoteOpWaitMillis。

• 如果 workingMillis 明显长于 remoteOpWaitMillis，则执行合并花费的时间最长。例如，100 中的 workingMillis 和 15 中的 remoteOpWaitMillis。

Queryable Encryption 日志校订

使用 Queryable Encryption 时，慢查询日志中会省略针对已加密集合的增删改查操作。有关详细信息，请参阅 Queryable Encryption 日志校订。

Enterprise 日志校订

仅适用于MongoDB Atlas和MongoDB Enterprise

使用 redactClientLogData 运行的 mongod 或 mongos 会在记录之前编辑与校订给定日志事件附带的任何消息，只留下与该事件相关的元数据、源文件或行号。redactClientLogData 以诊断细节为代价，防止潜在的敏感信息进入系统日志。

For example, the following operation inserts a document into a mongod running without log redaction. The mongod has the log verbosity level set to 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 结构化日志时，您可以使用第三方 jq 命令行实用程序轻松美观地打印日志条目，并提供强大的基于键的匹配和过滤功能。

jq 是一个开源 JSON 解析器，用于 Linux、Windows 和 macOS。

这些示例使用 jq 简化日志解析。

jq -r ".msg" /var/log/mongodb/mongod.log | sort | uniq -c | sort -rn | head -10

jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | sort | uniq -c | sort -r

jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | awk -F':' '{print $1}' | sort | uniq -c | sort -r

jq -cr '.attr.doc.driver' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn

jq -r '.attr.doc.os.type' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn

jq 'select(.attr.workingMillis>=2000)' /var/log/mongodb/mongod.log

jq 'select(.c=="REPL")' /var/log/mongodb/mongod.log

jq 'select(.c!="REPL")' /var/log/mongodb/mongod.log

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

{"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"}}

jq 'select( .id as $id | [22943, 22944] | index($id) )' /var/log/mongodb/mongod.log

jq 'select(.t["$date"] >= "2020-04-15T00:00:00.000" and .t["$date"] <= "2020-04-15T23:59:59.999")' /var/log/mongodb/mongod.log

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

日志摄取服务

日志摄取服务是一种第三方产品，摄取和汇总日志文件（通常来自分布式系统集群），并在中央位置对这些数据进行持续分析。

The JSON log format allows for more flexibility when working with log ingestion and analysis services. Whereas plaintext logs generally require some manner of transformation before being eligible for use with these products, JSON files can often be consumed out of the box, depending on the service. Further, JSON-formatted logs offer more control when performing filtering for these services, as the key-value structure offers the ability to specifically import only the fields of interest, while omitting the rest.

有关更多信息，请参阅所选第三方日志摄取服务的文档。

启动警告

此示例显示启动警告：

{
  "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"
  ]
}

客户端连接

This example shows a client connection that includes client data:

{
  "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

  操作的总延迟。

• inUseTrackedMemBytes

  8.3版本新增。

  当前查询操作使用的跟踪内存的字节数。

• peakTrackedMemBytes

  8.3版本新增。

  当前查询操作使用的跟踪内存的最大字节数。

{
   "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,
      "inUseTrackedMemBytes":368,
      "peakTrackedMemBytes":795,
      "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字段。 未来的MongoDB版本将删除已弃用的 queryHash字段，您需要改用 planCacheShapeHash字段。

转义

This example demonstrates character escaping, as shown in the setName field of the attribute object:

{
  "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 } }"
  }
}

查看

Starting in MongoDB 5.0, log messages for slow queries on views include a resolvedViews field that contains the view details:

"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 } } ] )

Assume a slow query is run on myView. The following example log message contains a resolvedViews field for myView:

{
   "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字段。 未来的MongoDB版本将删除已弃用的 queryHash字段，您需要改用 planCacheShapeHash字段。

授权

Starting in MongoDB 5.0, log messages for slow queries include a system.profile.authorization section. These metrics help determine if a request is delayed because of contention for the user authorization cache.

"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 字段。

缓存刷新时间

Starting in MongoDB 6.1, log messages for slow queries include the following cache refresh time fields:

Starting in MongoDB 7.0, log messages for slow queries also include the catalogCacheIndexLookupDurationMillis field that indicates the time that the operation spent fetching information from the index cache. This release also renames the shardVersionRefreshMillis field to placementVersionRefreshDurationMillis.

placementVersionRefreshDurationMillis 是为以下操作刷新缓存的时间：

• createCollection

• shardCollection

• dropCollection

• moveChunk

• renameCollection

• reshardCollection

• refineCollectionShardKey

• mergeChunks

• split

以下示例包括：

• 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
  }
}

查询内存限制已超出

从 MongoDB 9.0 开始，如果查询操作超过了单次操作内存限制且无法溢出到磁盘，MongoDB 将终止该操作并返回 ExceededMemoryLimit 错误。MongoDB 还会写入以下日志消息：

{
  "t": {
    "$date": "2026-09-02T15:16:17.180+00:00"
  },
  "s": "E",
  "c": "QUERY",
  "id": 12932700,
  "ctx": "conn3",
  "svc": "R",
  "msg": "Query exceeded the memory limit",
  "attr": {
    "error": "expression evaluation needs too much memory. Needs: 1140850688 bytes. Local memory limit: 1073741824 bytes. Global memory used: 1140850688 bytes. Global memory limit: 1073741824 bytes."
  }
}

error 属性是一个字符串，其中包含内存超额的详细信息。详细信息包括超出限制的操作、正在使用的内存量以及适用的内存限制。MongoDB 还会将此 string 返回给 ExceededMemoryLimit 错误中的客户端。

仅当操作超过单次操作内存限制且无法溢出到磁盘时，MongoDB 才会写入此日志消息。如果一个可以溢出到磁盘的阶段超过了限制，并且 allowDiskUse 为 false，MongoDB 将以 QueryExceededMemoryLimitNoDiskUseAllowed 错误结束操作，并且不会写入此日志消息。