sdlc.dev

MongoDB path · Finding things fast · Topic 4 of 12

Reading explain()

Not started

explain() asks MongoDB how it would run a query, or how it did. The answer is a tree of stages, each feeding documents or index keys to the one above, plus counters for how much each stage touched. Learning to read three or four stage names and two counters is enough to diagnose most slow queries.

Why it matters: A query that returns 30 documents can still read 200,000. explain() is how you see that before your users do.

  1. 1Plans are trees of stages

    COLLSCAN reads every document; IXSCAN walks an index; FETCH loads documents; SORT sorts in memory; PROJECTION_COVERED answers from the index alone.

  2. 2Compare examined with returned

    totalKeysExamined and totalDocsExamined against nReturned is the quickest health check. Close to 1:1 is good.

  3. 3The planner races candidates

    When several indexes could serve a query, MongoDB tries the candidate plans briefly, keeps the winner and caches it for that query shape.

  4. 4Pick the verbosity

    queryPlanner shows the chosen plan without running it; executionStats runs it and adds counts and timings; allPlansExecution adds the losing candidates.

1

How it works

The explanation, with examples you can run.

From a collection scan to an index

On a collection of 200,001 orders, with no index on customerId:

db.orders.find({ customerId: 42 }).explain("executionStats")

The full output is long. These are the fields that matter (the stage chain is read bottom-up, from executionStats.executionStages and its inputStages):

{ "winningPlan": "COLLSCAN", "nReturned": 32, "totalKeysExamined": 0,  "totalDocsExamined": 200001, "executionTimeMillis": 58 }

Every document was read to return 32. After db.orders.createIndex({ customerId: 1 }):

{ "winningPlan": "FETCH <- IXSCAN customerId_1", "nReturned": 32,  "totalKeysExamined": 32, "totalDocsExamined": 32, "executionTimeMillis": 0 }

IXSCAN walked the index to the 32 matching keys and FETCH loaded each document. Ratios close to 1:1 are what you want.

In-memory sorts and covered queries

Add .sort({ createdAt: -1 }) and the plan becomes SORT <- FETCH <- IXSCAN customerId_1. The index finds the documents but not in date order, so they are sorted in memory. For 32 documents that costs nothing; for 50,000 it is the slow part, and a sort stage that needs more than 100 MB spills to disk (allowed by default since 6.0). With an index on { customerId: 1, createdAt: -1 } the SORT stage disappears. If the projection asks only for fields in the index, MongoDB need not fetch documents at all:

db.orders.find({ customerId: 42 }, { _id: 0, customerId: 1, createdAt: 1 }).sort({ createdAt: -1 })
{ "winningPlan": "PROJECTION_COVERED <- IXSCAN customerId_1_createdAt_-1",  "nReturned": 32, "totalKeysExamined": 32, "totalDocsExamined": 0 }

totalDocsExamined: 0 is a covered query. Exclude _id explicitly, or it has to be fetched.

How the plan is chosen

When several indexes could serve a query, the planner runs the candidate plans for a short trial, picks the one that produced results with the least work, and caches it for that query shape (the filter, sort and projection shape, not the values). From MongoDB 8.3 a cost-based ranker backs up this trial when it cannot decide. explain("allPlansExecution") shows the losers too. hint() forces an index, which is useful for comparing plans while you test, and risky to leave in application code. To find slow queries in the first place, use the slow query log (operations over 100 ms by default) or the database profiler.

2

Check yourself

3 questions. Get them all right to finish this topic.

  1. 1.explain shows totalDocsExamined: 200001 and nReturned: 32. What does that tell you?
  2. 2.The winning plan is SORT <- FETCH <- IXSCAN. What is the SORT stage telling you?
  3. 3.Which verbosity should you use to see how many keys and documents a query really examined?

0 of 3 right so far. Get all three to finish this topic.

Go deeper