← Debugging Guides

阅读中文版本

MongoDB slow query — Use the Profiler and explain() to Find It

Diagnose MongoDB slow queries with the database profiler and executionStats, then fix collection scans, missing indexes, and oversized result sets.

intermediatedebuggingmongodbperformance

Symptoms

  • API latency spikes while CPU and memory look normal
  • The profiler shows operations taking hundreds of milliseconds
  • explain() reports COLLSCAN for a query that should use an index
  • docsExamined is far larger than nReturned

Possible causes

  • No index supports the query predicate or sort order
  • An index exists but the query cannot use it because of a leading wildcard regex or type mismatch
  • The query returns thousands of documents when the caller needs a projection and a limit
  • A background index build, replication catch-up, or lock contention inflates latency temporarily

Diagnosis steps

Enable profiling for slow operations

mongosh "mongodb://localhost:27017/app" --eval 'db.setProfilingLevel(2, { slowms: 100 }); db.getProfilingStatus()'

Interpretation

Level 2 records every operation above slowms. Use level 1 in production if the write overhead of full profiling is a concern.

Read the slowest recorded operations

mongosh "mongodb://localhost:27017/app" --eval 'db.system.profile.find({ millis: { $gt: 100 } }).sort({ millis: -1 }).limit(5).forEach(d => printjson({ op: d.op, ns: d.ns, millis: d.millis, planSummary: d.planSummary, docsExamined: d.docsExamined, keysExamined: d.keysExamined, nreturned: d.nreturned }))'

Interpretation

planSummary COLLSCAN means a collection scan; IXSCAN means an index was used. A large gap between docsExamined and nreturned shows the index or predicate is inefficient.

Run explain with execution statistics

mongosh "mongodb://localhost:27017/app" --eval 'printjson(db.orders.find({ customerId: "C-1042", status: "open" }).sort({ createdAt: -1 }).limit(20).explain("executionStats"))'

Interpretation

Check totalKeysExamined, totalDocsExamined, and nReturned in executionStats. Also read the winningPlan stages for SORT or COLLSCAN, which mean work happens after the index lookup.

Inspect currently running operations

mongosh "mongodb://localhost:27017/admin" --eval 'db.currentOp({ secs_running: { $gt: 5 }, active: true })'

Interpretation

Long-running operations can hold locks or saturate I/O even if the slow query itself is indexed. Look at the op, ns, and planSummary fields for the immediate cause.

Root cause

MongoDB must examine documents to satisfy a predicate that no index covers. Without a suitable compound index, the server scans the collection, then may sort the matching documents in memory. Even with an index, a query that filters on a non-prefix field or sorts by a different key forces extra document fetches or a blocking SORT stage, so latency grows with collection size rather than result size.

Fix

Create a compound index that follows the equality-sort-range order for the query, for example customerId, status, createdAt, and make sure the sort direction matches. Add a projection and a limit so the server returns only what the caller needs. For existing large collections, build indexes during a low-traffic window and monitor replication lag. Remove indexes that duplicate the same prefix.

Risk note

Every index slows writes and consumes memory. A poorly ordered compound index will not be used for the sort even if it covers the filter. Index builds on large collections can increase I/O and replication lag, and hidden indexes still exist on disk until dropped.

Verify the fix

Re-run explain('executionStats') and confirm the winning plan uses IXSCAN without a blocking SORT, with totalDocsExamined close to nReturned. Watch the profiler for a full traffic cycle and verify p95 query time and CPU both fall.

Measure before you index

MongoDB exposes slow operations through the database profiler. Enable it at level 2 with a threshold, reproduce the traffic, then sort by duration:

db.setProfilingLevel(2, { slowms: 100 })
db.system.profile.find({ millis: { $gt: 100 } })
  .sort({ millis: -1 }).limit(5)
  .forEach(d => printjson({
    ns: d.ns, millis: d.millis, planSummary: d.planSummary,
    docsExamined: d.docsExamined, nreturned: d.nreturned
  }));

planSummary is the fastest signal: COLLSCAN means no usable index, IXSCAN means an index was chosen. docsExamined far above nreturned means the index is not selective enough for the predicate.

Read explain like a query plan

db.orders.find({ customerId: "C-1042", status: "open" })
  .sort({ createdAt: -1 }).limit(20)
  .explain("executionStats")

Look at totalKeysExamined, totalDocsExamined, and nReturned, then inspect winningPlan. A SORT stage means the index did not provide the requested order, and the server is sorting in memory. COLLSCAN means it read the whole collection.

Fix the access path

Design the compound index around the query: equality fields first, then the sort field, then range fields. For the query above, { customerId: 1, status: 1, createdAt: -1 } lets the server seek and return already ordered documents.

db.orders.createIndex(
  { customerId: 1, status: 1, createdAt: -1 },
  { name: "orders_by_customer_status_recent" }
)

Add .projection({ orderId: 1, total: 1, createdAt: 1 }) and a bounded limit. Check db.currentOp() for unrelated long operations before blaming the query itself.

Verify with the same evidence

Re-run explain("executionStats"): the winning plan should use IXSCAN, totalDocsExamined should be close to nReturned, and no blocking SORT should appear. Then leave the profiler on for a business cycle and confirm the operations above slowms disappear from system.profile.