Query uses correct index still takes long execution time

Question

I am working on optimizing the mongo query. One of the queries is taking too long to execute on the index. Sharing the code snippet below:

Here is the command copied from Atlas:

  "command": {
    "getMore": 5992505034453534,
    "collection": "data",
    "$db": "prod",
    "$clusterTime": {
      "clusterTime": {
        "$timestamp": {
          "t": 1670439680,
          "i": 1071
        }
      },

  "originatingCommand": {
    "find": "data",
    "filter": {
      "accountId": "QQQAAQAQAQAQA",
      "custId": "62a7b11fy883bhedge73",
      "state": {
        "$in": [
          "INITIALIZING",
          "RUNNING"
        ]
      },
      "startTime": {
        "$lte": {
          "$date": "2022-12-07T17:39:28.573Z"
        }
      }
    },
    "maxTimeMS": 300000,

....

  "planSummary": [
    {
      "IXSCAN": {
        "accountId": 1,
        "custId": 1,
        "state": 1,
        "startTime": 1
      }
    }
  ],
  "cursorid": 5992505034144062000,
  "keysExamined": 2520,
  "docsExamined": 2519,
  "cursorExhausted": 1,
  "numYields": 130,
  "nreturned": 2519,
  "reslen": 4898837,

I have the below Index on Mongo:

Index Name: accountId_custId_state_startTime
accountId:1  custId:1  state:1  startTime:1  

Atlas Stats:

Index Size: 776.5MB Usage: 73.58/min

I do not understand why the execution time is too high. Why it's taking 1672ms to query?

Answer 1

From an indexing perspective, the operation is perfectly efficient:

  "keysExamined": 2520,
  "docsExamined": 2519,
  "nreturned": 2519,

It only scanned the relevant portion of the index, pulling only documents that were sent back to the client as part of the result set. There is nothing that can be improved from an indexing perspective here. Therefore any observed slowness is likely being caused by "something else".

In general it shouldn't take the database 1.6 seconds to process 2,519 documents (~5MB). But without knowing more about your environment we can't really say anything more specific. Is there a meaningful amount of concurrent workload that may be competing for resources here? Is the cluster itself undersized for the workload? It is notable that the ratio of yields to documents returned seems higher than usual, which could be an indicator of problems like these.

I would recommend looking at the overall health of the cluster and at the other operations that are running at the same time. My impression is that running this operation in isolation would probably result in it executing faster, further suggesting that the problem (and therefore the resolution as well) is somewhere other than the index used by this operation.