Code Summary: Identifying and Analyzing Slow Queries in the MongoDB Shell

Enable the Database Profiler

Here’s an example of enabling the Database Profiler:

db.setProfilingLevel(1)

The value passed as the argument determines the profiling level. The Database Profiler has the following profiling levels:

0 - The profiler is off and does not collect any data. This is the default profiler level.

1 - The profiler collects data for operations that exceed the slowms threshold or match a specified filter.

2 - The profiler collects data for all operations.

Here is an example of setting the Database Profiler to capture all operations that take longer than 50 milliseconds to execute by supplying a slowms threshold.

db.setProfilingLevel(1, { slowms: 50 })

Query the Database Profiler

Here is an example of how to query the Database Profiler for the top query sorted by longest operation times in milliseconds.

db.system.profile.find().sort({millis: -1}).limit(1)
[
  {
    op: 'query',
    ns: 'sample_airbnb.listingsAndReviews',
    command: {
      find: 'listingsAndReviews',
      filter: {
        'address.market': 'Rio De Janeiro',
        price: { '$lte': Decimal128('200.00') },
        bedrooms: { '$gte': 2 },
        minimum_nights: { '$lte': '2' },
        amenities: 'Wifi'
      },
      sort: { price: -1 },
      projection: {
        listing_url: 1,
        name: 1,
        property_type: 1,
        minimum_nights: 1,
        bedrooms: 1,
        amenities: 1,
        price: 1,
        'address.market': 1,
        _id: 0
      },
      apiVersion: '1',
      lsid: { id: UUID('d34b837f-ae63-499d-9ac3-103436397d0a') },
      '$clusterTime': {
        clusterTime: Timestamp({ t: 1739404444, i: 1 }),
        signature: {
          hash: Binary.createFromBase64('fjgh1wfz1zfb4YwyhURuGGCv2z4=', 0),
          keyId: Long('7430811807452758018')
        }
      },
      '$db': 'sample_airbnb'
    },
    keysExamined: 63,
    docsExamined: 14,
    fromMultiPlanner: true,
    nBatches: 1,
    cursorExhausted: true,
    numYield: 5,
    nreturned: 14,
    planCacheShapeHash: 'C39BEC33',
    planCacheKey: '24D99D4D',
    queryShapeHash: '7CC9C566FBEC7456338D861AA79FA03BBE88C53C11D2749F31EAA64ABBD38042',
    queryFramework: 'classic',
    locks: { Global: { acquireCount: { r: Long('7') } } },
    flowControl: {},
    readConcern: { level: 'local', provenance: 'implicitDefault' },
    storage: {
      data: { bytesRead: Long('4785220'), timeReadingMicros: Long('80718') }
    },
    responseLength: 10256,
    protocol: 'op_msg',
    cpuNanos: 18346272,
    millis: 106,
    planSummary: 'IXSCAN { address.market: 1, amenities: 1, price: -1, bedrooms: 1, minimum_nights: 1, listing_url: 1, name: 1, property_type: 1 }',
    planningTimeMicros: 106690,
    execStats: {
      isCached: false,
      stage: 'PROJECTION_DEFAULT',
      nReturned: 14,
      executionTimeMillisEstimate: 30,
      works: 64,
      advanced: 14,
      needTime: 48,
      needYield: 0,
      saveState: 5,
      restoreState: 5,
      isEOF: 1,
      transformBy: {},
      inputStage: {
        stage: 'FETCH',
        nReturned: 14,
        executionTimeMillisEstimate: 30,
        works: 64,
        advanced: 14,
        needTime: 48,
        needYield: 0,
        saveState: 5,
        restoreState: 5,
        isEOF: 1,
        docsExamined: 14,
        alreadyHasObj: 0,
        inputStage: {
          stage: 'IXSCAN',
          nReturned: 14,
          executionTimeMillisEstimate: 10,
          works: 63,
          advanced: 14,
          needTime: 48,
          needYield: 0,
          saveState: 5,
          restoreState: 5,
          isEOF: 1,
          keyPattern: {
            'address.market': 1,
            amenities: 1,
            price: -1,
            bedrooms: 1,
            minimum_nights: 1,
            listing_url: 1,
            name: 1,
            property_type: 1
          },
          indexName: 'address.market_1_amenities_1_price_-1_bedrooms_1_minimum_nights_1_listing_url_1_name_1_property_type_1',
          isMultiKey: true,
          multiKeyPaths: {
            'address.market': [],
            amenities: [ 'amenities' ],
            price: [],
            bedrooms: [],
            minimum_nights: [],
            listing_url: [],
            name: [],
            property_type: []
          },
          isUnique: false,
          isSparse: false,
          isPartial: false,
          indexVersion: 2,
          direction: 'forward',
          indexBounds: {
            'address.market': [ '["Rio De Janeiro", "Rio De Janeiro"]' ],
            amenities: [ '["Wifi", "Wifi"]' ],
            price: [ '[200.00, -inf.0]' ],
            bedrooms: [ '[2, inf.0]' ],
            minimum_nights: [ '["", "2"]' ],
            listing_url: [ '[MinKey, MaxKey]' ],
            name: [ '[MinKey, MaxKey]' ],
            property_type: [ '[MinKey, MaxKey]' ]
          },
          keysExamined: 63,
          seeks: 49,
          dupsTested: 14,
          dupsDropped: 0
        }
      }
    },
    ts: ISODate('2025-02-12T23:54:26.426Z'),
    client: '255.255.255.255',
    appName: 'mongosh 2.3.6',
    allUsers: [ { user: 'user', db: 'admin' } ],
    user: 'user@admin'
  }
]

Disable the Database Profiler

Here’s an example of how to disable the Database profiler

db.setProfilingLevel(0)

Search the MongoDB Log Files

You can use the grep command to search the MongoDB log files for slow operations

grep "Slow query" /path/to/logfile

This will return the log entries that were recorded for queries that exceeded the slowms threshold as seen here:

{"t":{"$date":"2025-01-08T18:06:37.637+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn7814","msg":"Slow query","attr":{"type":"command","isFromUserConnection":true,"ns":"sample_airbnb.listingsAndReviews_big_collection","collectionType":"normal","appName":"mongosh 2.3.6","queryShapeHash":"4E96296E301A995A57D8622997052D4AC355B7BA8702E4461739A9D10A65EC38","command":{"find":"listingsAndReviews_big_collection","filter":{"property_type":"House","room_type":"Entire home/apt","minimum_nights":{"$gt":2},"maximum_nights":{"$lte":30},"bedrooms":{"$gte":2}},"sort":{"number_of_reviews":-1},"apiVersion":"1","lsid":{"id":{"$uuid":"690c1cdb-5148-43bb-b551-d5ea935780e0"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1736359504,"i":1}},"signature":{"hash":{"$binary":{"base64":"bUmxaMztfcHfJ3PKP+8Wz8lJeAQ=","subType":"0"}},"keyId":7397043374412267521}},"$db":"sample_airbnb"},"planSummary":"COLLSCAN","planningTimeMicros":203,"keysExamined":0,"docsExamined":55550,"hasSortStage":true,"nBatches":1,"cursorExhausted":true,"numYields":199,"nreturned":0,"planCacheShapeHash":"16DDFF73","planCacheKey":"E3E1C84F","queryFramework":"classic","reslen":261,"locks":{"Global":{"acquireCount":{"r":201}}},"readConcern":{"level":"local","provenance":"implicitDefault"},"storage":{"data":{"bytesRead":893739220,"timeReadingMicros":3073882},"timeWaitingMicros":{"cache":4}},"cpuNanos":949972045,"remote":"104.30.134.190:37157","protocol":"op_msg","queues":{"execution":{"admissions":200},"ingress":{"admissions":1}},"workingMillis":3746,"durationMillis":3746}}