Log Messages

Log Message Format (Console/Log File)

Starting in MongoDB 3.0, MongoDB includes the severity level and the component for each log message when output to theconsole or a logfile (i.e. not to syslog [1]).

The log messages have the form:

  1. <timestamp> <severity> <component> [<context>] <message>

For example:

  1. 2014-11-03T18:28:32.450-0500 I NETWORK [initandlisten] waiting for connections on port 27017
[1]Syslog messages follow the standard syslog message format. Startingin version 4.2, MongoDB includes the component in its log messages to syslog.

Logging Slow Operations

Client operations appear in the log if their duration exceeds theslow operation threshold or when thelog verbosity level is 1 orhigher. [3] These log entries include the full commandobject associated with the operation.

Starting in MongoDB 4.2, the profiler entries and the diagnosticlog messages (i.e. mongod/mongos logmessages) for read/write operations include:

  • queryHash to help identify slow queries with the samequery shape.
  • planCacheKey to provide more insight into the query plancache for slow queries.

The following example output includes information abouta slow aggregation operation:

  1. 2019-01-14T12:00:59.166-0500 I COMMAND  [conn4] command test.items appName: "MongoDB Shell" command: aggregate { aggregate: "items", pipeline: [ { $match: { a: { $lte: 500.0 } } }, { $sort: { a: -1.0 } } ], allowDiskUse: true, cursor: {}, lsid: { id: UUID("a73100a6-2f4d-48b7-a119-4632491c20eb") }, $db: "test" } planSummary: IXSCAN { a: 1, _id: -1 } cursorid:4808731480531288834 keysExamined:12524506 docsExamined:25003 hasSortStage:1 usedDisk:1 fromMultiPlanner:1 numYields:98113 nreturned:101 queryHash:811451DD planCacheKey:759981BA reslen:1305014 locks:{ Global: { acquireCount: { r: 98211, w: 98211 } }, Database: { acquireCount: { r: 98211 } }, Collection: { acquireCount: { r: 98211 } } } storage:{ data: { bytesRead: 112803842, timeReadingMicros: 62720 } } protocol:op_msg 39658ms

Timestamp (Console/Log File)

When logging to the console or a logfile [2], the defaultformat for the <timestamp> is iso8601-local. To modify thetimestamp format, use the —timeStampFormat runtime option or thesystemLog.timeStampFormat setting.

[2]If logging to syslog, the syslog daemon generates timestampswhen it logs a message, not when MongoDB issues the message. Thiscan lead to misleading timestamps for log entries, especially whenthe system is under heavy load.

Severity Levels

The following table lists the severity levels associated with each logmessage:

LevelDescription
FFatal
EError
WWarning
IInformational, for Verbosity Level of 0
D[1-5]Debug, for All Verbosity Levels > 0Starting in version 4.2, MongoDB logs the debug verbositylevel. For example, ifverbosity level is 2, MongoDB logs D2.In previous versions, MongoDB log messages only specified Dfor Debug level.

You can specify the verbosity level of various components to determinethe amount of Informational and Debug messages MongoDB outputs. [3]

To set verbosity levels, see Configure Log Verbosity Levels.

Client Data

New in version 3.4.

Client application debugging and performance monitoring is easierwhen you can clearly match server events with particular clientrequests. With this in mind, recent MongoDBdrivers and clientapplications (including the mongo shell) have the abilityto send identifying information at the time of connection to theserver. After the connection is established, the client does not sendthe identifying information again unless the connection is droppedand reestablished.

The exact fields included vary by client. Below is a sample clientdata document:

  1. {
  2.    application: {
  3.      name: "MongoDB Shell"
  4.    },
  5.    driver: {
  6.       name: "MongoDB Internal Client",
  7.       version: "3.4.0"
  8.    },
  9.    os: {
  10.       type: "Darwin",
  11.       name: "Mac OS X",
  12.       architecture: "x86_64",
  13.       version: "15.3.0"
  14.    }
  15. }

When secondary members of areplica set initiatea connection to a primary, they send similar data. A typicalconnection document is as follows:

  1. {
  2.    driver: {
  3.       name: "NetworkInterfaceASIO-Replication",
  4.       version: "3.4.0"
  5.    },
  6.    os: {
  7.       type: "Darwin",
  8.       name: "Mac OS X",
  9.       architecture: "x86_64",
  10.       version: "15.3.0"
  11.    }
  12. }

For a complete description of client information and required fields,see theMongoDB Handshake specification.

Components

Log messages now include components, providing functionalcategorization of the messages:

REPL is the parent component of ELECTION. IfsystemLog.component.replication.election.verbosity isunset, MongoDB uses the REPL verbosity level forELECTION components.

  • FTDC

New in version 3.2.

Messages related to the diagnostic data collection mechanism, suchas 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 asverifying the GeoJSON shapes. To specify the log level forGEO components, set thesystemLog.component.geo.verbosity parameter.

REPL is the parent component of INITSYNC. IfsystemLog.component.replication.initialSync.verbosity isunset, MongoDB uses the REPL verbosity level forINITSYNC components.

REPL is the parent component of REPL_HB. IfsystemLog.component.replication.heartbeats.verbosity isunset, MongoDB uses the REPL verbosity level forREPL_HB components.

REPL is the parent component of ROLLBACK. IfsystemLog.component.replication.rollback.verbosity isunset, MongoDB uses the REPL verbosity level forROLLBACK components.

STORAGE is the parent component of JOURNAL. IfsystemLog.component.storage.journal.verbosity isunset, MongoDB uses the STORAGE verbosity level forJOURNAL components.

  • -
  • Messages not associated with a named component. Unnamed componentshave the default log level specified in thesystemLog.verbosity setting. ThesystemLog.verbosity setting is the default setting forboth named and unnamed components.

Verbosity Levels

View Current Log Verbosity Level

To view the current verbosity levels, use thedb.getLogComponents() method.

Configure Log Verbosity Levels

You can configure the verbosity level using: thesystemLog.verbosity andsystemLog.component.<name>.verbosity settings, thelogComponentVerbosity parameter; thedb.setLogLevel() method. [3]

systemLog Verbosity Settings

To configure the default log level for all components, use thesystemLog.verbosity setting. To configure the level ofspecific components, use the systemLog.component.<name>.verbositysettings.

For example, the following configuration sets thesystemLog.verbosity to 1, thesystemLog.component.query.verbosity to 2, thesystemLog.component.storage.verbosity to 2, and thesystemLog.component.storage.journal.verbosity to 1:

  1. systemLog:
  2.    verbosity: 1
  3.    component:
  4.       query:
  5.          verbosity: 2
  6.       storage:
  7.          verbosity: 2
  8.          journal:
  9.             verbosity: 1

All components not specified in the configuration have thesystemLog.verbosity of 1.

logComponentVerbosity Parameter

To set the logComponentVerbosity parameter, pass adocument 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 thestorage.journal to 1.

  1. db.adminCommand( {
  2.    setParameter: 1,
  3.    logComponentVerbosity: {
  4.       verbosity: 1,
  5.       query: {
  6.          verbosity: 2
  7.       },
  8.       storage: {
  9.          verbosity: 2,
  10.          journal: {
  11.             verbosity: 1
  12.          }
  13.       }
  14.    }
  15. } )

db.setLogLevel()

Use the db.setLogLevel() method to update a single componentlog level. For a component, you can specify verbosity level of 0 to5, or you can specify -1 to inherit the verbosity of theparent. For example, the following sets thesystemLog.component.query.verbosity to its parent verbosity(i.e. default verbosity):

  1. db.setLogLevel(-1, "query")
[3](1, 2, 3, 4) Starting in version 4.2 (also available starting in 4.0.6), secondary members of a replica set nowlog oplog entries that take longer than the slowoperation threshold to apply. These slow oplog messages are loggedfor the secondaries in the diagnostic log under the REPL component with the text appliedop: <oplog entry> took <num>ms. These slow oplog entries dependonly on the slow operation threshold. They do not depend on the loglevels (either at the system or component level), or the profilinglevel, or the slow operation sample rate. The profiler does notcapture slow oplog entries.