Log Messages
On this page本页内容
Overview概述
As part of normal operation, MongoDB maintains a running log of events, including entries such as incoming connections, commands run, and issues encountered. 作为正常操作的一部分,MongoDB维护事件的运行日志,包括传入连接、运行的命令和遇到的问题等条目。Generally, log messages are useful for diagnosing issues, monitoring your deployment, and tuning performance.通常,日志消息对于诊断问题、监视部署和调整性能非常有用。
Structured Logging结构化日志记录
Starting in MongoDB 4.4, 从MongoDB 4.4开始,mongod
/ mongos
instances output all log messages in structured JSON format. mongod
/mongos
实例以结构化JSON格式输出所有日志消息。Log entries are written as a series of key-value pairs, where each key indicates a log message field type, such as "severity", and each corresponding value records the associated logging information for that field type, such as "informational". Previously, log entries were output as plaintext.日志条目被写成一系列键值对,其中每个键指示日志消息字段类型,例如“严重性”,每个相应的值记录该字段类型的相关日志信息,例如“信息性”。以前,日志条目以明文形式输出。
The following is an example log message in JSON format as it would appear in the MongoDB log file:以下是一个JSON格式的日志消息示例,它将出现在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"}}
JSON log entries can be pretty-printed for readability. Here is the same log entry pretty-printed:为了可读性,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"
}
}
In this log entry, for example, the key 例如,在此日志条目中,表示严重性的键s
, representing severity, has a corresponding value of I
, representing "Informational", and the key c
, representing component, has a corresponding value of NETWORK
, indicating that the "network" component was responsible for this particular message. s
具有相应的值I
,表示“Information”,而表示组件的键c
具有相应的数值NETWORK
,表示“NETWORK”组件负责此特定消息。The various field types are presented in detail in the Log Message Field Types section.日志消息字段类型部分详细介绍了各种字段类型。
Structured logging with key-value pairs allows for efficient parsing by automated tools or log ingestion services, and makes programmatic search and analysis of log messages easier to perform. 具有键值对的结构化日志记录允许通过自动化工具或日志接收服务进行高效解析,并使日志消息的程序化搜索和分析更容易执行。Examples of analyzing structured log messages can be found in the Parsing Structured Log Messages section.分析结构化日志消息的示例可以在解析结构化日志消息部分找到。
The 如果mongod
quits if it's unable to write to the log file. mongod
无法写入日志文件,它就会退出。To ensure that 为了确保mongod
can write to the log file, verify that the log volume has space on the disk and the logs are rotated.mongod
可以写入日志文件,请验证日志卷在磁盘上是否有空间,并且日志是否已旋转。
JSON Log Output FormatJSON日志输出格式
Starting in MongoDB 4.4, all log output is in JSON format including output sent to:从MongoDB 4.4开始,所有日志输出都是JSON格式,包括发送到以下位置的输出:
- Log file
- Syslog
- Stdout (standard out) log destinations
Output from the getLog
command is also in JSON format.getLog
命令的输出也是JSON格式。
Each log entry is output as a self-contained JSON object which follows the Relaxed Extended JSON v2.0 specification, and has the following layout and field order:每个日志条目都作为一个独立的JSON对象输出,该对象遵循Relaxed Extended 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)
}
Field descriptions:字段描述:
Field Name | ||
---|---|---|
t | Datetime | |
s | String | |
c | String | |
id | Integer | |
ctx | String | |
msg | String | |
attr | Object | attr object is omitted.attr 对象。msg message body, depending on the message. msg 消息正文中由其键名称引用。 |
tags | Array of strings | ["startupWarnings"] .["startupWarnings"] 。 |
truncated | Object | attr attribute.attr 属性时才包括。 |
size | Object | attr attribute.attr 属性时才包括。 |
Escaping正在逃离
The message and attributes fields will escape control characters as necessary according to the Relaxed Extended JSON v2.0 specification:根据Relaxed Extended JSON v2.0规范,消息和属性字段将根据需要转义控制字符:
Quotation Mark (" ) | \" |
Backslash (\ ) | \\ |
Backspace (0x08 ) | \b |
Formfeed (0x0C ) | \f |
Newline (0x0A ) | \n |
Carriage return (0x0D ) | \r |
Horizontal tab (0x09 ) | \t |
Control characters not listed above are escaped with 上面未列出的控制字符用\uXXXX
where "XXXX" is the unicode codepoint in hexadecimal. \uXXXX
转义,其中“XXXX”是十六进制的unicode代码点。Bytes with invalid UTF-8 encoding are replaced with the unicode replacement character represented by UTF-8编码无效的字节将替换为\ufffd
.\ufffd
表示的unicode替换字符。
An example of message escaping is provided in the examples section.示例部分提供了消息转义的示例。
Truncation截断
Any attributes that exceed the maximum size defined with 任何超过maxLogSizeKB
(default: 10 KB) are truncated. maxLogSizeKB
定义的最大大小(默认值:10 KB)的属性都将被截断。Truncated attributes omit log data beyond the configured limit, but retain the JSON formatting of the entry to ensure that the entry remains parsable.截断的属性会忽略超出配置限制的日志数据,但会保留条目的JSON格式,以确保条目保持可解析性。
Here is an example of a log entry with a truncated attribute:以下是一个具有截断属性的日志条目示例:
{"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}}
In this case, the 在这种情况下,request
attribute has been truncated and the specific instance of its subfield _id
that triggered truncation (i.e. caused the attribute to overrun maxLogSizeKB
) is printed without data as {"_id":{}}
. request
属性已被截断,其子字段_id
的触发截断的特定实例(即,导致属性超过maxLogSizeKB
)将在没有数据的情况下打印为{"_id":{}}
。The remainder of the request
attribute is then omitted.request
属性的其余部分将被省略。
Log entries containing one or more truncated attributes include a 包含一个或多个截断属性的日志条目包括一个truncated
object which provides the following information for each truncated attribute in the log entry:truncated
对象,该截断对象为日志条目中的每个截断属性提供以下信息:
the attribute that was truncated被截断的属性the specific subobject of that attribute that triggered truncation, if applicable.触发截断的属性的特定子对象(如果适用)。the data截断字段的数据type
of the truncated fieldtype
the截断字段的size
of the truncated fieldsize
Log entries with truncated attributes may also include an additional 具有截断属性的日志条目还可以在条目末尾包括额外的size
field at the end of the entry which indicates the original size of the attribute before truncation, in this case 46328
or about 46KB. size
字段,该字段指示截断之前的属性的原始大小,在这种情况下为46328或大约46KB。This final 只有当最终大小字段与截断对象中的大小字段不同时,即,如果属性的总对象大小与截断子对象的大小不同,才会显示此最终大小字段,如上例所示。size
field is only shown if it is different from the size
field in the truncated
object, i.e. if the total object size of the attribute is different from the size of the truncated subobject, as is the case in the example above.
Padding衬料
When output to the file or the syslog log destinations, padding is added after the severity, context, and id fields to increase readability when viewed with a fixed-width font.当输出到文件或系统日志目的地时,会在严重性、上下文和id字段后面添加填充,以提高使用固定宽度字体查看时的可读性。
The following MongoDB log file excerpt demonstrates this padding:以下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"}}}
Pretty Printing漂亮的印刷
When working with MongoDB structured logging, the third-party jq command-line utility当使用MongoDB结构化日志记录时,第三方jq命令行实用程序 is a useful tool that allows for easy pretty-printing of log entries, and powerful key-based matching and filtering.
是一个有用的工具,可以轻松漂亮地打印日志条目,并提供强大的基于键的匹配和筛选。
jq
is an open-source JSON parser, and is available for Linux, Windows, and macOS.是一个开源JSON解析器,可用于Linux、Windows和macOS。
You can use 您可以使用jq
to pretty-print log entries as follows:jq
漂亮地打印日志条目,如下所示:
Pretty-print the entire log file:漂亮地打印整个日志文件:cat mongod.log | jq
Pretty-print the most recent log entry:漂亮地打印最近的日志条目:cat mongod.log | tail -1 | jq
More examples of working with MongoDB structured logs are available in the Parsing Structured Log Messages section.有关使用MongoDB结构化日志的更多示例,请参阅解析结构化日志消息部分。
Configuring Log Message Destinations配置日志消息目的地
MongoDB log messages can be output to file, syslog, or stdout (standard output).MongoDB日志消息可以输出到file、syslog或stdout(标准输出)。
To configure the log output destination, use one of the following settings, either in the configuration file or on the command-line:
Configuration file:配置文件:-
- The
systemLog.destination
option for file or syslog
- The
Command-line:命令行:
Not specifying either file or syslog sends all logging output to stdout.
For the full list of logging settings and options see:
- Configuration file:
- Command-line:
-
- Log options list for
mongod
- Log options list for
mongos
- Log options list for
Error messages sent to stderr
(standard error), such as fatal errors during startup when not using the file or syslog log destinations, or messages having to do with misconfigured logging settings, are not affected by the log output destination setting, and are printed to stderr
in plaintext format.
Log Message Field Types日志消息字段类型
Timestamp
The timestamp field type indicates the precise date and time at which the logged event occurred.时间戳字段类型指示所记录事件发生的确切日期和时间。
{
"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"
}
}
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.
See Filtering by Date Range for log parsing examples that filter on the timestamp field.有关筛选时间戳字段的日志解析示例,请参阅按日期范围筛选。
Starting in MongoDB 4.4, the 从MongoDB 4.4开始,不再支持ctime
timestamp format is no longer supported.ctime
时间戳格式。
[1] | If logging to syslog, the syslog daemon generates timestamps when it logs a message, not when MongoDB issues the message. This can lead to misleading timestamps for log entries, especially when the system is under heavy load. |
Severity严重性
The severity field type indicates the severity level associated with the logged event.严重性字段类型指示与记录的事件相关联的严重性级别。
{
"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"
}
}
Severity levels range from "Fatal" (most severe) to "Debug" (least severe):严重性级别从“致命”(最严重)到“调试”(最不严重)不等:
Level | |
---|---|
F | Fatal |
E | Error |
W | Warning |
I | Informational, for verbosity level 0 |
D1 - D5 | Debug, for verbosity levels > 0 MongoDB indicates the specific debug verbosity level. For example, if verbosity level is 2, MongoDB indicates D2 .D for all debug verbosity levels. D 。 |
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.
Components组件
The component field type indicates the category a logged event is a member of, such as NETWORK or COMMAND.组件字段类型指示记录的事件所属的类别,例如NETWORK或COMMAND。
{
"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"
}
}
Each component is individually configurable via its own verbosity filter. The available components are as follows:每个组件都可以通过自己的详细度筛选器进行单独配置。可用组件如下:
ACCESS
-
Messages related to access control, such as authentication.与访问控制相关的消息,如身份验证。To specify the log level forACCESS
components, use thesystemLog.component.accessControl.verbosity
setting.
COMMAND
-
Messages related to database commands, such as
count
. To specify the log level forCOMMAND
components, use thesystemLog.component.command.verbosity
setting.
CONTROL
-
Messages related to control activities, such as initialization.与控制活动相关的消息,如初始化。To specify the log level forCONTROL
components, use thesystemLog.component.control.verbosity
setting.
ELECTION
-
Messages related specifically to replica set elections.专门与副本集选择相关的消息。To specify the log level forELECTION
components, set thesystemLog.component.replication.election.verbosity
parameter.REPL
is the parent component ofELECTION
. IfsystemLog.component.replication.election.verbosity
is unset, MongoDB uses theREPL
verbosity level forELECTION
components.
FTDC
-
Messages related to the diagnostic data collection mechanism, such as server statistics and status messages.与诊断数据集合机制相关的消息,如服务器统计信息和状态消息。To specify the log level forFTDC
components, use thesystemLog.component.ftdc.verbosity
setting.
GEO
-
Messages related to the parsing of geospatial shapes, such as verifying the GeoJSON shapes.与地理空间形状解析相关的消息,例如验证GeoJSON形状。To specify the log level forGEO
components, set thesystemLog.component.geo.verbosity
parameter.
INDEX
-
Messages related to indexing operations, such as creating indexes.与索引操作相关的消息,例如创建索引。To specify the log level forINDEX
components, set thesystemLog.component.index.verbosity
parameter.
INITSYNC
-
Messages related to initial sync operation.与初始同步操作相关的消息。To specify the log level forINITSYNC
components, set thesystemLog.component.replication.initialSync.verbosity
parameter.REPL
is the parent component ofINITSYNC
. IfsystemLog.component.replication.initialSync.verbosity
is unset, MongoDB uses theREPL
verbosity level forINITSYNC
components.
JOURNAL
-
Messages related specifically to storage journaling activities.专门与存储日记活动相关的消息。To specify the log level forJOURNAL
components, use thesystemLog.component.storage.journal.verbosity
setting.STORAGE
is the parent component ofJOURNAL
. IfsystemLog.component.storage.journal.verbosity
is unset, MongoDB uses theSTORAGE
verbosity level forJOURNAL
components.
NETWORK
-
Messages related to network activities, such as accepting connections.与网络活动相关的消息,例如接受连接。To specify the log level forNETWORK
components, set thesystemLog.component.network.verbosity
parameter.
QUERY
-
Messages related to queries, including query planner activities.与查询相关的消息,包括查询计划器活动。To specify the log level forQUERY
components, set thesystemLog.component.query.verbosity
parameter.
RECOVERY
-
Messages related to storage recovery activities.与存储恢复活动相关的消息。To specify the log level forRECOVERY
components, use thesystemLog.component.storage.recovery.verbosity
setting.STORAGE
is the parent component ofRECOVERY
. IfsystemLog.component.storage.recovery.verbosity
is unset, MongoDB uses theSTORAGE
verbosity level forRECOVERY
components.
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 thesystemLog.component.replication.verbosity
parameter.REPL
is the parent component of theELECTION
,INITSYNC
,REPL_HB
, andROLLBACK
components.
REPL_HB
-
Messages related specifically to replica set heartbeats. To specify the log level for
REPL_HB
components, set thesystemLog.component.replication.heartbeats.verbosity
parameter.REPL
is the parent component ofREPL_HB
. IfsystemLog.component.replication.heartbeats.verbosity
is unset, MongoDB uses theREPL
verbosity level forREPL_HB
components.
ROLLBACK
-
Messages related to rollback operations. To specify the log level for
ROLLBACK
components, set thesystemLog.component.replication.rollback.verbosity
parameter.REPL
is the parent component ofROLLBACK
. IfsystemLog.component.replication.rollback.verbosity
is unset, MongoDB uses theREPL
verbosity level forROLLBACK
components.
SHARDING
-
Messages related to sharding activities, such as the startup of the
mongos
. To specify the log level forSHARDING
components, use thesystemLog.component.sharding.verbosity
setting.
STORAGE
-
Messages related to storage activities, such as processes involved in the
fsync
command. To specify the log level forSTORAGE
components, use thesystemLog.component.storage.verbosity
setting.
TXN
New in version 4.0.2.4.0.2版新增。Messages related to multi-document transactions. To specify the log level for
TXN
components, use thesystemLog.component.transaction.verbosity
setting.
WRITE
-
Messages related to write operations, such as
update
commands. To specify the log level forWRITE
components, use thesystemLog.component.write.verbosity
setting.
WT
New in version 5.3.5.3版新增。Messages related to the WiredTiger storage engine. To specify the log level for
WT
components, use thesystemLog.component.storage.wt.verbosity
setting.
WTBACKUP
New in version 5.3.5.3版新增。Messages related to backup operations performed by the WiredTiger storage engine. To specify the log level for the
WTBACKUP
components, use thesystemLog.component.storage.wt.wtBackup.verbosity
setting.
WTCHKPT
New in version 5.3.5.3版新增。Messages related to checkpoint operations performed by the WiredTiger storage engine. To specify the log level for
WTCHKPT
components, use thesystemLog.component.storage.wt.wtCheckpoint.verbosity
setting.
WTCMPCT
New in version 5.3.5.3版新增。Messages related to compaction operations performed by the WiredTiger storage engine. To specify the log level for
WTCMPCT
components, use thesystemLog.component.storage.wt.wtCompact.verbosity
setting.
WTEVICT
New in version 5.3.5.3版新增。Messages related to eviction operations performed by the WiredTiger storage engine. To specify the log level for
WTEVICT
components, use thesystemLog.component.storage.wt.wtEviction.verbosity
setting.
WTHS
New in version 5.3.5.3版新增。Messages related to the history store of the WiredTiger storage engine. To specify the log level for
WTHS
components, use thesystemLog.component.storage.wt.wtHS.verbosity
setting.
WTRECOV
New in version 5.3.5.3版新增。Messages related to recovery operations performed by the WiredTiger storage engine. To specify the log level for
WTRECOV
components, use thesystemLog.component.storage.wt.wtRecovery.verbosity
setting.
WTRTS
New in version 5.3.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 thesystemLog.component.storage.wt.wtRTS.verbosity
setting.
WTSLVG
New in version 5.3.5.3版新增。Messages related to salvage operations performed by the WiredTiger storage engine. To specify the log level for
WTSLVG
components, use thesystemLog.component.storage.wt.wtSalvage.verbosity
setting.
WTTIER
New in version 5.3.5.3版新增。Messages related to tiered storage operations performed by the WiredTiger storage engine. To specify the log level for
WTTIER
components, use thesystemLog.component.storage.wt.wtTiered.verbosity
setting.
WTTS
New in version 5.3.5.3版新增。Messages related to timestamps used by the WiredTiger storage engine. To specify the log level for
WTTS
components, use thesystemLog.component.storage.wt.wtTimestamp.verbosity
setting.
WTTXN
New in version 5.3.5.3版新增。Messages related to transactions performed by the WiredTiger storage engine. To specify the log level for
WTTXN
components, use thesystemLog.component.storage.wt.wtTransaction.verbosity
setting.
WTVRFY
New in version 5.3.5.3版新增。Messages related to verification operations performed by the WiredTiger storage engine. To specify the log level for
WTVRFY
components, use thesystemLog.component.storage.wt.wtVerify.verbosity
setting.
WTWRTLOG
New in version 5.3.5.3版新增。Messages related to log write operations performed by the WiredTiger storage engine. To specify the log level for
WTWRTLOG
components, use thesystemLog.component.storage.wt.wtWriteLog.verbosity
setting.
-
-
Messages not associated with a named component. Unnamed components have the default log level specified in the
systemLog.verbosity
setting. ThesystemLog.verbosity
setting is the default setting for both named and unnamed components.
See Filtering by Component for log parsing examples that filter on the component field.
Client Data
MongoDB Drivers and client applications (including mongosh
) have the ability to 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.
This identifying information is contained in the attributes field of the log entry. The exact information included varies by client.
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","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"}}}}
When secondary members of a replica set initiate a connection to a primary, they send similar data. A sample log message containing this initiation connection might appear as follows. The client data is contained in the doc
object in the attributes
field:
{"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"}}}}
See the examples section for a pretty-printed example showing client data.
For a complete description of client information and required fields, see the MongoDB Handshake specification.
Verbosity Levels
You can specify the logging verbosity level to increase or decrease the amount of log messages MongoDB outputs. Verbosity levels can be adjusted for all components together, or for specific named components individually.
Verbosity affects log entries in the severity categories Informational and Debug only. Severity categories above these levels are always shown.
You might set verbosity levels to a high value to show detailed logging for debugging or development, or to a low value to minimize writes to the log on a vetted production deployment. [2]
View Current Log Verbosity Level
To view the current verbosity levels, use the db.getLogComponents()
method:
db.getLogComponents()
Your output might resemble the following:
{
"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.
Configure Log Verbosity Levels
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 Settings
To configure the default log level for all components, use the systemLog.verbosity
setting. To configure the level of specific components, use the systemLog.component.<name>.verbosity
settings.
For example, the following configuration sets the systemLog.verbosity
to 1
, the systemLog.component.query.verbosity
to 2
, the systemLog.component.storage.verbosity
to 2
, and the systemLog.component.storage.journal.verbosity
to 1
:
systemLog:
verbosity: 1
component:
query:
verbosity: 2
storage:
verbosity: 2
journal:
verbosity: 1
You would set these values in the configuration file or on the command line for your mongod
or mongos
instance.
All components not specified explicitly in the configuration have a verbosity level of -1
, indicating that they inherit the verbosity level of their parent, if they have one, or the global verbosity level (systemLog.verbosity
) if they do not.
logComponentVerbosity
Parameter
To set the logComponentVerbosity
parameter, pass a document with the verbosity settings to change.
For example, the following sets the default verbosity level
to 1
, the query
to 2
, the storage
to 2
, and the storage.journal
to 1
.
db.adminCommand( {
setParameter: 1,
logComponentVerbosity: {
verbosity: 1,
query: {
verbosity: 2
},
storage: {
verbosity: 2,
journal: {
verbosity: 1
}
}
}
} )
You would set these values from mongosh
.
db.setLogLevel()
Use the db.setLogLevel()
method to update a single component log level. For a component, you can specify verbosity level of 0
to 5
, or you can specify -1
to inherit the verbosity of the parent. For example, the following sets the systemLog.component.query.verbosity
to its parent verbosity (i.e. default verbosity):
db.setLogLevel(-1, "query")
You would set this value from mongosh
.
[2] | (1, 2, 3, 4, 5) Starting in version 4.2, secondary members of a replica set now log oplog entries that take longer than the slow operation threshold to apply. These slow oplog messages:
|
Logging Slow Operations
Client operations (such as queries) appear in the log if their duration exceeds the slow operation threshold or when the log verbosity level is 1 or higher. [2] These log entries include the full command object associated with the operation.
Starting in MongoDB 4.2, the profiler entries and the diagnostic log messages (i.e. mongod/mongos log messages) for read/write operations include:
queryHash
to help identify slow queries with the same query shape.planCacheKey
to provide more insight into the query plan cache for slow queries.
Starting in MongoDB 5.0, slow operation log messages include a remote
field specifying client IP address.
Starting in MongoDB 6.2, slow operation log messages include a queryFramework
field that indicates which query engine executed the query:
queryFramework: "classic"
indicates that the classic engine executed the query.queryFramework: "sbe"
indicates that the slot-based query execution engine executed the query.
Starting in MongoDB 6.1, slow operation log messages include cache refresh time fields.
Starting in MongoDB 6.3, slow operation log messages and database profiler entries include a cpuNanos
field that specifies the total CPU time spent by a query operation in nanoseconds. The cpuNanos
field is only available on Linux systems.
Starting in MongoDB 7.0, the totalOplogSlotDurationMicros
in the slow query log message shows the time between a write operation getting a commit timestamp to commit the storage engine writes and actually committing. mongod
supports parallel writes. However, it commits write operations with commit timestamps in any order.
Consider the following writes with commit timestamps:
- writeA with Timestamp1
- writeB with Timestamp2
- writeC with Timestamp3
Suppose writeB commits first at Timestamp2. Replication is paused until writeA commits because writeA's oplog entry with Timestamp1 is required for replication to copy the oplog to secondary replica set members.
For a pretty-printed example of a slow operation log entry, see Log Message Examples.
Time Waiting for Shards Logged in remoteOpWaitMillis
Field
New in version 5.0. 5.0版新增。
Starting in MongoDB 5.0, you can use the remoteOpWaitMillis
log field to obtain the wait time (in milliseconds) for results from shards.
remoteOpWaitMillis
is only logged:
- If you configure slow operations logging.
- On the shard or
mongos
that merges the results.
To determine if a merge operation or a shard issue is causing a slow query, compare the durationMillis
and remoteOpWaitMillis
time fields in the log. durationMillis
is the total time the query took to complete. Specifically:
- If
durationMillis
is slightly longer thanremoteOpWaitMillis
, then most of the time was spent waiting for a shard response. For example,durationMillis
of 17 andremoteOpWaitMillis
of 15. - If
durationMillis
is significantly longer thanremoteOpWaitMillis
, then most of the time was spent performing the merge. For example,durationMillis
of 100 andremoteOpWaitMillis
of 15.
Log Redaction
Queryable Encryption Log Redaction
When using Queryable Encryption, CRUD operations against encrypted collections are omitted from the slow query log. For details, see Queryable Encryption redaction.
Enterprise Log Redaction
Available in MongoDB Enterprise only
A mongod
or mongos
running with redactClientLogData
redacts any message accompanying a given log event before logging, leaving only metadata, source files, or line numbers related to the event. redactClientLogData
prevents potentially sensitive information from entering the system log at the cost of diagnostic detail.
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" } )
This operation produces the following log event:
2017-06-09T13:35:23.446-04:00 I COMMAND [conn1] command internal.clients
appName: "MongoDB Shell"
command: insert {
insert: "clients",
documents: [ {
_id: ObjectId('593adc5b99001b7d119d0c97'),
name: "Joe",
PII: " Sensitive Information"
} ],
ordered: true
}
...
When mongod
runs with redactClientLogData
and performs the same insert operation, it produces the following log event:
2017-06-09T13:45:18.599-04:00 I COMMAND [conn1] command internal.clients
appName: "MongoDB Shell"
command: insert {
insert: "###", documents: [ {
_id: "###", name: "###", PII: "###"
} ],
ordered: "###"
}
Use redactClientLogData
in conjunction with Encryption at Rest and TLS/SSL (Transport Encryption) to assist compliance with regulatory requirements.
Parsing Structured Log Messages
Log parsing is the act of programmatically searching through and analyzing log files, often in an automated manner. With the introduction of structured logging in MongoDB 4.4, log parsing is made simpler and more powerful. For example:例如:
- Log message fields are presented as key-value pairs. Log parsers can query by specific keys of interest to efficiently filter results.
- Log messages always contain the same message structure. Log parsers can reliably extract information from any log message, without needing to code for cases where information is missing or formatted differently.
The following examples demonstrate common log parsing workflows when working with MongoDB JSON log output.
Log Parsing Examples
When working with MongoDB structured logging, the third-party jq command-line utility is a useful tool that allows for easy pretty-printing of log entries, and powerful key-based matching and filtering.
jq
is an open-source JSON parser, and is available for Linux, Windows, and macOS.
These examples use jq
to simplify log parsing.
Counting Unique Messages
The following example shows the top 10 unique message values in a given log file, sorted by frequency:
jq -r ".msg" /var/log/mongodb/mongod.log | sort | uniq -c | sort -rn | head -10
Monitoring Connections
Remote client connections are shown in the log under the "remote" key in the attribute object. The following counts all unique connections over the course of the log file and presents them in descending order by number of occurrences:
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | sort | uniq -c | sort -r
Note that connections from the same IP address, but connecting over different ports, are treated as different connections by this command. You could limit output to consider IP addresses only, with the following change:
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | awk -F':' '{print $1}' | sort | uniq -c | sort -r
Analyzing Driver Connections
The following example counts all remote MongoDB driver connections, and presents each driver type and version in descending order by number of occurrences:
jq -cr '.attr.doc.driver' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
Analyzing Client Types
The following example analyzes the reported client data of remote MongoDB driver connections and client applications, including mongosh
, and prints a total for each unique operating system type that connected, sorted by frequency:
jq -r '.attr.doc.os.type' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
The string "Darwin", as reported in this log field, represents a macOS client.
Analyzing Slow Queries
With slow operation logging enabled, the following returns only the slow operations that took above 2000 milliseconds:, for further analysis:
jq '. | select(.attr.durationMillis>=2000)' /var/log/mongodb/mongod.log
Consult the jq documentation for more information on the
jq
filters shown in this example.
Filtering by Component
Log components (the third field in the JSON log output format) indicate the general category a given log message falls under. Filtering by component is often a great starting place when parsing log messages for relevant events.
The following example prints only the log messages of component type REPL:
jq '. | select(.c=="REPL")' /var/log/mongodb/mongod.log
The following example prints all log messages except those of component type REPL:
jq '. | select(.c!="REPL")' /var/log/mongodb/mongod.log
The following example print log messages of component type REPL or STORAGE:
jq '. | select( .c as $c | ["REPL", "STORAGE"] | index($c) )' /var/log/mongodb/mongod.log
Consult the jq documentation for more information on the
jq
filters shown in this example.
Filtering by Known Log ID
Log IDs (the fifth field in the JSON log output format) map to specific log events, and can be relied upon to remain stable over successive MongoDB releases.
As an example, you might be interested in the following two log events, showing a client connection followed by a disconnection:
{"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"}}
The log IDs for these two entries are 22943
and 22944
respectively. You could then filter your log output to show only these log IDs, effectively showing only client connection activity, using the following jq
syntax:
jq '. | select( .id as $id | [22943, 22944] | index($id) )' /var/log/mongodb/mongod.log
Consult the jq documentation for more information on the
jq
filters shown in this example.
Filtering by Date Range
Log output can be further refined by filtering on the timestamp field, limiting log entries returned to a specific date range. For example, the following returns all log entries that occurred on April 15th, 2020:
jq '. | select(.t["$date"] >= "2020-04-15T00:00:00.000" and .t["$date"] <= "2020-04-15T23:59:59.999")' /var/log/mongodb/mongod.log
Note that this syntax includes the full timestamp, including milliseconds but excluding the timezone offset.
Filtering by date range can be combined with any of the examples above, creating weekly reports or yearly summaries for example. The following syntax expands the "Monitoring Connections" example from earlier to limit results to the month of May, 2020:
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
Consult the jq documentation for more information on the
jq
filters shown in this example.
Log Ingestion Services
Log ingestion services are third-party products that intake and aggregate log files, usually from a distributed cluster of systems, and provide ongoing analysis of that data in a central location.
The JSON log format, introduced with MongoDB 4.4, 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.
Consult the documentation for your chosen third-party log ingestion service for more information.
Log Message Examples
The following examples show log messages in JSON output format.
These log messages are presented in pretty-printed format for convenience.
Startup Warning
This example shows a startup warning:
{
"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"
]
}
Client Connection
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",
"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"
}
}
}
}
Slow Operation
This example shows a slow operation message:
{
"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
}
}
Escaping
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",
"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 } }"
}
}
View
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
} ]
The following example uses the test
database and creates a view named myView
that sorts the documents in myCollection
by the firstName
field:
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",
"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
}
}
}
Authorization
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
},
Session Workflow Log Message
Starting in MongoDB 6.3, a message is added to the log if the time to send an operation response exceeds the slowms threshold option.
The message is known as a session workflow log message and contains various times to perform an operation in a database session.
Example session workflow log message:
{
"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
}
}
}
The times are in milliseconds.
A session workflow message is added to the log if sendResponseMillis
exceeds the slowms threshold option.
totalMillis | Total time to perform the operation in the session, which includes the time spent waiting for a message to be received. |
activeMillis | Time between receiving a message and completing the operation associated with that message. Time includes sending a response and performing any clean up. |
receivedWorkMillis | Time to receive the operation information over the network. |
processWorkMillis | Time to process the operation and create the response. |
sendResponseMillis | Time to send the response. |
yieldMillis | Time between releasing the worker thread and the thread being used again. |
finalize | Time to end and close the session workflow. |
Connection Acquisition To Wire Log Message
Starting in MongoDB 6.3, a message is added to the log if the time that an operation waited between acquisition of a server connection and writing the bytes to send to the server over the network exceeds 1 millisecond.
By default, the message is logged at the "I"
information level, and at most once every second to avoid too many log messages. If you must obtain every log message, change your log level to debug.
If the operation wait time exceeds 1 millisecond and the message is logged at the information level within the last second, then the next message is logged at the debug level. Otherwise, the next message is logged at the information level.
Example log message:
{
"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
}
}
The following table describes the durationMicros
field in attr
.
durationMicros | Time in microseconds that the operation waited between acquisition of a server connection and writing the bytes to send to the server over the network. |
Cache Refresh Times
Starting in MongoDB 6.1, log messages for slow queries include the following cache refresh time fields:
catalogCacheDatabaseLookupDurationMillis
catalogCacheCollectionLookupDurationMillis
databaseVersionRefreshDurationMillis
shardVersionRefreshMillis
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 placementVersionRefreshMillis
.
The following example includes:
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 Syslog Limitations
In a Linux system, messages are subject to the rules defined in the Linux configuration file /etc/systemd/journald.conf
. By default, log message bursts are limited to 1000 messages within a 30 second period. To see more messages, increase the RateLimitBurst
parameter in /etc/systemd/journald.conf
.