← Recipes

阅读中文版本

Profile MongoDB Slow Queries and Read the Plan

Enable the profiler at slowms, read explain output for scanStage and index use, and add the compound index the plan says is missing.

~30 mindatabasemongodbperformance

Task

Capture slow operations with the MongoDB profiler, interpret their query plans, and fix the missing index or bad shape causing COLLSCAN.

When to use this

A collection grew from one million to fifty million documents and one aggregate stage now dominates latency. Nobody knows whether it scans or uses indexes.

Prerequisites

  • MongoDB 4.4+ with profiling privileges on the database
  • A test environment or the ability to profile at a conservative threshold
  • The slow operation text from logs or the profiler

Steps

1. Enable profiling for slow operations only.

mongosh shop --eval 'db.setProfilingLevel(1, { slowms: 100 })'

Expected output: Operations slower than 100 ms are recorded in system.profile without collecting noise from fast queries.

2. List the slowest operations with their plans.

mongosh shop --eval 'db.system.profile.find({}).sort({ millis: -1 }).limit(5).pretty()'

Expected output: The top entries show the namespace, the query shape, millis, and planSummary fields such as COLLSCAN marking a full collection scan.

3. Explain the worst query shape in detail.

mongosh shop --eval 'db.orders.find({ customerId: 4711, status: "shipped" }).sort({ shippedAt: -1 }).explain("executionStats")'

Expected output: The winning plan shows COLLSCAN plus a SORT stage: no index covers the filter, and the sort happens in memory after scanning everything.

4. Create the compound index matching the shape.

db.orders.createIndex(
  { customerId: 1, status: 1, shippedAt: -1 },
  { background: true }
)

Expected output: Equality fields lead the index, then the sort field in the query direction, letting the plan become IXSCAN with no SORT stage.

5. Re-explain and verify the improvement.

mongosh shop --eval 'db.orders.find({ customerId: 4711, status: "shipped" }).sort({ shippedAt: -1 }).explain("executionStats")'

Expected output: The winning plan shows IXSCAN on the new index, totalDocsExamined collapses from millions to the returned count, and executionTimeMillis drops accordingly.

Troubleshooting

Problem

Profiler writes hurt production

Solution

Raise slowms instead of disabling profiling entirely, and query system.profile with a time filter; the overhead of level 1 at a high threshold is negligible.

Problem

Index exists but COLLSCAN persists

Solution

The query shape does not fit the index prefix; equality fields in the query must appear as a prefix of the compound index.

Problem

Plan flip-flops between indexes

Solution

Competing indexes with similar prefixes confuse the planner; consolidate into one wider compound index and drop the redundant ones.

Limitations

  • system.profile is a capped collection that forgets old entries; export findings if you need history.
  • executionStats cost depends on cache warmth; compare plans under similar cache conditions.

planSummary never lies

MongoDB tells you exactly how it executed a query: the profiler records slow operations with their plan summaries, and explain with executionStats counts every document examined. COLLSCAN means it read the whole collection; a SORT stage after a scan means it sorted all of that in memory. Reading those two labels before writing any index is the difference between fixing the query and decorating it.

// Profiler: only the slow stuff
db.setProfilingLevel(1, { slowms: 100 })

// The shape that hurts
db.orders.find({ customerId: 4711, status: "shipped" })
  .sort({ shippedAt: -1 })
  .explain("executionStats")

// The fix: equality prefix, then sort field
db.orders.createIndex({ customerId: 1, status: 1, shippedAt: -1 })

docsExamined is the headline number

Latency in MongoDB is mostly a function of how many documents the server touched to answer. When totalDocsExamined is millions and nReturned is twenty, the query reads a million times more than it needs, and no hardware upgrade fixes that ratio. A correct index collapses examined to returned, and the number proves it happened.

Index to the shape, not to the field

A single-field index on customerId still leaves the status filter and the sort to post-processing. Compound indexes must start with the equality fields in the query and end with the sort field in its direction. Only then does IXSCAN deliver documents in ready order with both filters applied on the walk.