Using MongoDB Explain with Mongoose

In MongoDB, the explain command tells the MongoDB server to return stats about how it executed a query, rather than the results of the query. Mongoose queries have an explain() function that converts a query into an explain().

const Character = mongoose.model('Character', mongoose.Schema({
  name: String,
  age: Number,
  rank: String
}));

await Character.create([
  { name: 'Jean-Luc Picard', age: 59, rank: 'Captain' },
  { name: 'William Riker', age: 29, rank: 'Commander' },
  { name: 'Deanna Troi', age: 28, rank: 'Lieutenant Commander' },
  { name: 'Geordi La Forge', age: 29, rank: 'Lieutenant' },
  { name: 'Worf', age: 24, rank: 'Lieutenant' }
]);

const explain = await Character.find({ name: /Picard/ }).explain().
  then(res => res[0]);
// Object describing how MongoDB planned to execute the query
explain.queryPlanner;
// Object containing stats about how MongoDB executed the query
explain.executionStats;

Reading the queryPlanner Output

The queryPlanner object contains more detailed information about how MongoDB decided to execute the query. For example, below is the queryPlanner object from the above explain() call.

{
  plannerVersion: 1,
  namespace: 'test.characters',
  indexFilterSet: false,
  parsedQuery: { name: { '$regex': 'Picard' } },
  winningPlan: {
    stage: 'COLLSCAN',
    filter: { name: { '$regex': 'Picard' } },
    direction: 'forward'
  },
  rejectedPlans: []
}

The most important piece of information is the winningPlan property, that contains the information about the plan MongoDB decided on to execute the query. In practice, winningPlan is useful for checking whether MongoDB used an index for the query or not.

A query plan is a list of stages used to identify the documents that match the query. The above plan has only one stage, 'COLLSCAN', which means MongoDB executed a full collection scan to answer the query. A collection scan means MongoDB searched through every document in the 'characters' collection to see if name matched the given query.

Query plans get more sophisticated when you introduce indexes. For example, suppose you add an index on name as shown below.

await Character.collection.createIndex({ name: 1 });

const explain = await Character.find({ name: 'Jean-Luc Picard' }).explain().
  then(res => res[0]);
// Object describing how MongoDB planned to execute the query
explain.queryPlanner;

The queryPlanner output looks like this:

{
  plannerVersion: 1,
  namespace: 'test.characters',
  indexFilterSet: false,
  parsedQuery: { name: { '$eq': 'Jean-Luc Picard' } },
  winningPlan: {
    stage: 'FETCH',
    inputStage: {
      stage: 'IXSCAN',
      keyPattern: { name: 1 },
      indexName: 'name_1',
      isMultiKey: false,
      multiKeyPaths: { name: [] },
      isUnique: false,
      isSparse: false,
      isPartial: false,
      indexVersion: 2,
      direction: 'forward',
      indexBounds: { name: [ '["Jean-Luc Picard", "Jean-Luc Picard"]' ] }
    }
  },
  rejectedPlans: []
}

The winningPlan property is a recursive structure: winningPlan points to the last stage in the winning query plan, and each stage has an inputStage property that described the previous stage.

In the above plan, there are two stages: 'IXSCAN' and 'FETCH'. That means first MongoDB used the { name: 1 } index to identify which documents matched the query, and then fetched the individual documents.

Reading the executionStats Output

The executionStats output is more complex than queryPlanner: it includes stats about how long each stage took and how many documents each stage scanned.

For example, below is the executionStats output for a simple collection scan:

{
  executionSuccess: true,
  nReturned: 1,
  executionTimeMillis: 0,
  totalKeysExamined: 0,
  totalDocsExamined: 5,
  executionStages: {
    stage: 'COLLSCAN',
    filter: { name: { '$regex': 'Picard' } },
    nReturned: 1,
    executionTimeMillisEstimate: 0,
    works: 7,
    advanced: 1,
    needTime: 5,
    needYield: 0,
    saveState: 0,
    restoreState: 0,
    isEOF: 1,
    direction: 'forward',
    docsExamined: 5
  },
  allPlansExecution: []
}

The important details to note here are the top-level executionTimeMillis and totalDocsExamined properties. executionTimeMillis is the amount of time MongoDB spent executing the query, and totalDocsExamined is the number of documents MongoDB had to look at to answer the query.

Keep in mind that executionTimeMillis does not include network latency or time spent blocked behind a slow train. Just because executionTimeMillis is small doesn't mean that the end user saw the result instantaneously.

When you have an index and multiple stages, executionStats breaks down the approximate execution time and number of documents scanned per stage. Below is the executionStats for a query with an index, with some of the less important details excluded for brevity:

{
  executionSuccess: true,
  nReturned: 1,
  executionTimeMillis: 2,
  totalKeysExamined: 1,
  totalDocsExamined: 1,
  executionStages: {
    stage: 'FETCH',
    nReturned: 1,
    executionTimeMillisEstimate: 0,
    // ...
    docsExamined: 1,
    // ...
    inputStage: {
      stage: 'IXSCAN',
      nReturned: 1,
      executionTimeMillisEstimate: 0,
      // ...
    }
  },
  allPlansExecution: []
}

The above executionStats output says that there were two stages: 'IXSCAN' and 'FETCH'. The 'IXSCAN' stage executed in 0ms and resulted in one document being sent to the 'FETCH' stage. The 'FETCH' stage examined 1 document, and returned 1 document, which was the final result of the query.

---

---

More Mongoose Tutorials

• trim() in Mongoose Schemas
• Implementing Soft Delete in Mongoose
• Using limit() with Mongoose Queries
• How to Fix "Buffering timed out after 10000ms" Error in Mongoose
• Using insertOne() in Mongoose
• Mongoose on('delete')
• Enums in Mongoose