Database Profiler Output
- Example system.profile Document
- Output Reference

Database Profiler Output

The database profiler captures data information about read and writeoperations, cursor operations, and database commands. To configure thedatabase profile and set the thresholds for capturing profile data,see the Database Profiler section.

The database profiler writes data in the system.profile collection,which is a capped collection. To view the profiler’s output,use normal MongoDB queries on the system.profile collection.

Note

Because the database profiler writes data to thesystem.profile collection in adatabase, the profiler will profile some write activity, even fordatabases that are otherwise read-only.

Changed in version 3.4.

currentOp and thedatabase profiler report the samebasic diagnostic information for all CRUD operations, including thefollowing:

These operations are also included in the logging ofslow queries (see slowOpThresholdMs formore information about slow query logging).

Example system.profile Document

The following presents some sample documents found in thesystem.profile collection foroperations on a standalone:

Find Operation
Update Operation

The following document in the system.profile reflects a find operation:

{
   "op" : "query",
   "ns" : "test.report",
   "command" : {
      "find" : "report",
      "filter" : { "a" : { "$lte" : 500 } },
      "lsid" : {
         "id" : UUID("5ccd5b81-b023-41f3-8959-bf99ed696ce9")
      },
      "$db" : "test"
   },
   "cursorid" : 33629063128,
   "keysExamined" : 101,
   "docsExamined" : 101,
   "fromMultiPlanner" : true,
   "numYield" : 2,
   "nreturned" : 101,
   "queryHash" : "811451DD",
   "planCacheKey" : "759981BA",
   "locks" : {
      "Global" : {
         "acquireCount" : {
            "r" : NumberLong(3),
            "w" : NumberLong(3)
         }
      },
      "Database" : {
         "acquireCount" : { "r" : NumberLong(3) },
         "acquireWaitCount" : { "r" : NumberLong(1) },
         "timeAcquiringMicros" : { "r" : NumberLong(69130694) }
      },
      "Collection" : {
         "acquireCount" : { "r" : NumberLong(3) }
      }
   },
   "storage" : {
      "data" : {
         "bytesRead" : NumberLong(14736),
         "timeReadingMicros" : NumberLong(17)
      }
   },
   "responseLength" : 1305014,
   "protocol" : "op_msg",
   "millis" : 69132,
   "planSummary" : "IXSCAN { a: 1, _id: -1 }",
   "execStats" : {
      "stage" : "FETCH",
      "nReturned" : 101,
      "executionTimeMillisEstimate" : 0,
      "works" : 101,
      "advanced" : 101,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 3,
      "restoreState" : 2,
      "isEOF" : 0,
      "docsExamined" : 101,
      "alreadyHasObj" : 0,
      "inputStage" : {
         ...
      }
   },
   "ts" : ISODate("2019-01-14T16:57:33.450Z"),
   "client" : "127.0.0.1",
   "appName" : "MongoDB Shell",
   "allUsers" : [
      {
         "user" : "someuser",
         "db" : "admin"
      }
   ],
   "user" : "someuser@admin"
}

The profile entry for update (anddelete) operation contains the entire updatecommand.

The following example reflects an updateoperation on a collection named report.

{
   "op" : "update",
   "ns" : "test.report",
   "command" : {
      "q" : { },
      "u" : { "$rename" : { "a" : "b" } },
      "multi" : true,
      "upsert" : false
   },
   "keysExamined" : 0,
   "docsExamined" : 25000,
   "nMatched" : 25000,
   "nModified" : 25000,
   "keysInserted" : 25000,
   "keysDeleted" : 25000000,
   "numYield" : 6985,
   "locks" : {
      "Global" : {
         "acquireCount" : { "r" : NumberLong(6986), "w" : NumberLong(13972) }
      },
      "Database" : {
         "acquireCount" : { "w" : NumberLong(6986) },
         "acquireWaitCount" : { "w" : NumberLong(1) },
         "timeAcquiringMicros" : { "w" : NumberLong(60899375) }
      },
      "Collection" : {
         "acquireCount" : { "w" : NumberLong(6986) }
      },
      "Mutex" : {
         "acquireCount" : { "r" : NumberLong(25000) }
      }
   },
   "storage" : {
      "data" : {
         "bytesRead" : NumberLong(126344060),
         "bytesWritten" : NumberLong(281834762),
         "timeReadingMicros" : NumberLong(94549),
         "timeWritingMicros" : NumberLong(139361)
      }
   },
   "millis" : 164687,
   "planSummary" : "COLLSCAN",
   "execStats" : {
      "stage" : "UPDATE",
      "nReturned" : 0,
      "executionTimeMillisEstimate" : 103771,
      "works" : 25003,
      "advanced" : 0,
      "needTime" : 25002,
      "needYield" : 0,
      "saveState" : 6985,
      "restoreState" : 6985,
      "isEOF" : 1,
      "nMatched" : 25000,
      "nWouldModify" : 25000,
      "wouldInsert" : false,
      "inputStage" : {
         "stage" : "COLLSCAN",
         "nReturned" : 25000,
         "executionTimeMillisEstimate" : 0,
         "works" : 25002,
         "advanced" : 25000,
         "needTime" : 1,
         "needYield" : 0,
         "saveState" : 31985,
         "restoreState" : 31985,
         "isEOF" : 1,
         "direction" : "forward",
         "docsExamined" : 25000
      }
   },
   "ts" : ISODate("2019-01-14T23:33:01.806Z"),
   "client" : "127.0.0.1",
   "appName" : "MongoDB Shell",
   "allUsers" : [
      {
         "user" : "someuser",
         "db" : "admin"
      }
   ],
   "user" : "someuser@admin"
}

Output Reference

For any single operation, the documents created by the databaseprofiler will include a subset of the following fields. The preciseselection of fields in these documents depends on the type ofoperation.

Starting in MongoDB 4.2 (and in 4.0.9), for slow operations, the profilerentries anddiagnostic log messages includestorage information.

Note

For the output specific to the version of your MongoDB, refer tothe appropriate version of the MongoDB Manual.

system.profile.op
The type of operation. The possible values are:
- command
- count
- distinct
- geoNear
- getMore
- group
- insert
- mapReduce
- query
- remove
- update

system.profile.ns
The namespace the operation targets. Namespaces in MongoDBtake the form of the database, followed by a dot (.),followed by the name ofthe collection.

system.profile.command

Changed in version 3.6.

A document containing the full command object associated with thisoperation.

For example, the following output contains the command object for afind operation on a collection named items in adatabase named test:

"command" : {
  "find" : "items",
  "filter" : {
    "sku" : 1403978
  },
  ...
  "$db" : "test"
}

The following example output contains the command object for agetMore operation generated bya command with cursor id 19234103609 on a collection nameditems in a database named test:

"command" : {
    "getMore" : NumberLong("19234103609"),
    "collection" : "items",
    "batchSize" : 10,
    ...
    "$db" : "test"
},

If the command document exceeds 50 kilobytes, thedocument has the following form:

"command" : {
  "$truncated": <string>,
  "comment": <string>
}

The $truncated field contains a string summary of the document excludingthe document’s comment field if present. If the summary still exceeds50 kilobytes then it is further truncated, denoted by an ellipsis(…) at the end of the string.

The comment field is present if a comment was passed to the operation.

system.profile.originatingCommand

Changed in version 3.6.

For "getmore" operations which retrieve the next batch ofresults from a cursor, the originatingCommand field contains thefull command object (e.g. find or aggregate) which originallycreated that cursor.

system.profile.cursorid
The ID of the cursor accessed by a query and getmoreoperations.

system.profile.keysExamined

Changed in version 3.2.0.

Renamed from system.profile.nscanned.The number of index keys that MongoDB scanned inorder to carry out the operation.

In general, if keysExamined is much higherthan nreturned, the database is scanning manyindex keys to find the result documents. Consider creating oradjusting indexes to improve query performance..

Changed in version 3.4.

keysExamined is available for the following commands andoperations:

system.profile.docsExamined

Changed in version 3.2.0: Renamed from system.profile.nscannedObjects.

The number of documents in the collection that MongoDB scanned inorder to carry out the operation.

Changed in version 3.4.

docsExamined is available for the following commands andoperations:

system.profile.hasSortStage

Changed in version 3.2.0: Renamed from system.profile.scanAndOrder.

hasSortStage is a boolean that is truewhen a query cannot use the ordering in the index to return therequested sorted results; i.e. MongoDB must sort the documents afterit receives the documents from a cursor. The field only appears whenthe value is true.

Changed in version 3.4.

hasSortStage is available for the following commands andoperations:

system.profile.usedDisk

New in version 4.2.

A boolean that indicates whether any aggregation stage wrote data totemporary files due to memory restrictions.

Only appears if usedDisk is true.

system.profile.ndeleted
The number of documents deleted by the operation.

system.profile.ninserted
The number of documents inserted by the operation.

system.profile.nMatched

New in version 2.6.

The number of documents that match the system.profile.querycondition for the update operation.

system.profile.nModified

New in version 2.6.

The number of documents modified by the update operation.

system.profile.upsert
A boolean that indicates the update operation’s upsert optionvalue. Only appears if upsert is true.

system.profile.fromMultiPlanner

New in version 3.2.5.

A boolean that indicates whether the query planner evaluated multipleplans before choosing the winning execution plan for the query.

Only present when value is true.

system.profile.replanned

New in version 3.2.5.

A boolean that indicates whether the query system evicted a cachedplan and re-evaluated all candidate plans.

Only present when value is true.

system.profile.keysInserted
The number of index keys inserted for a given write operation.

system.profile.keysDeleted
Removed in 3.4.

The number of index keys the update changed inthe operation. Changing an index key carries a small performancecost because the database must remove the old key and inserts a newkey into the B-tree index.

system.profile.writeConflicts

New in version 3.0.0.

The number of conflicts encountered during the write operation; e.g.an update operation attempts to modify the same document asanother update operation. See also write conflict.

system.profile.numYield
The number of times the operation yielded to allow other operationsto complete. Typically, operations yield when they need access todata that MongoDB has not yet fully read into memory. This allowsother operations that have data in memory to complete while MongoDBreads in data for the yielding operation. For more information,see the FAQ on when operations yield.

system.profile.queryHash
A hexadecimal string that represents a hash of the queryshape and is dependent only on the query shape. queryHash canhelp identify slow queries (including the query filter of writeoperations) with the same query shape.

Note

As with any hash function, two different query shapes may resultin the same hash value. However, the occurrence of hashcollisions between different query shapes is unlikely.

For more information on queryHash and planCacheKey, seequeryHash and planCacheKey.

New in version 4.2.

system.profile.planCacheKey
A hash of the key for the plan cache entry associated with the query.

Unlike the queryHash, theplanCacheKey is a function ofboth the query shape and the currently available indexes forthat shape. That is, if indexes that can support the queryshape are added/dropped, the planCacheKey value may changewhereas the queryHash value would not change.

For more information on queryHash and planCacheKey, seequeryHash and planCacheKey.

New in version 4.2.

system.profile.locks

New in version 3.0.0: locks replaces the lockStats field.

The system.profile.locks provides information for variouslock types and lock modes heldduring the operation.

The possible lock types are:

Lock TypeDescriptionParallelBatchWriterModeRepresents a lock for parallel batch writer mode.

In earlier versions, PBWM information was reported as part ofthe Global lock information.

New in version 4.2.

ReplicationStateTransitionRepresents lock taken for replica set member state transitions.

New in version 4.2.

GlobalRepresents global lock.DatabaseRepresents database lock.CollectionRepresents collection lock.MutexRepresents mutex.MetadataRepresents metadata lock.oplogRepresents lock on the oplog.

The possible locking modes for the lock types are as follows:

Lock ModeDescriptionRRepresents Shared (S) lock.WRepresents Exclusive (X) lock.rRepresents Intent Shared (IS) lock.wRepresents Intent Exclusive (IX) lock.

The returned lock information for the various lock types include:

system.profile.locks.acquireCount
Number of times the operation acquired the lock in the specifiedmode.
system.profile.locks.acquireWaitCount
Number of times the operation had to wait for theacquireCount lock acquisitionsbecause the locks were held in a conflicting mode.acquireWaitCount is less than orequal to acquireCount.
system.profile.locks.timeAcquiringMicros
Cumulative time in microseconds that the operation had to wait toacquire the locks.

timeAcquiringMicros divided byacquireWaitCount gives anapproximate average wait time for the particular lock mode.

system.profile.locks.deadlockCount
Number of times the operation encountered deadlocks while waitingfor lock acquisitions.

For more information on lock modes, seeWhat type of locking does MongoDB use?.

system.profile.storage