Databases Bug Report

MongoDB query slow despite an index: in-memory SORT and the ESR rule

A shipment timeline query had a compound index yet still took 2.4 seconds. explain() showed a blocking SORT stage and 180,000 documents examined for 50 results. Reordering the index by Equality, Sort, Range fixed it.

Daniel Tran Daniel Tran @fun_dev · June 03, 2025 · 10 min read · 4 Views
Banner: MongoDB compound index reordered by the Equality, Sort, Range rule to remove an in-memory sort

Our shipment tracking API has an endpoint that returns the latest events for one customer account, filtered to the last 30 days and sorted newest first. It had been fine for a year. In May the p95 latency for GET /accounts/{id}/events crept from 90 ms to 2.4 s for our three largest accounts, and the Atlas Profiler started listing the query on every page of slow operations.

The slow query log entry looked like this (trimmed):

{"t":{"$date":"2025-05-27T08:14:02.311+00:00"},"s":"I","c":"COMMAND","id":51803,
 "ctx":"conn4412","msg":"Slow query","attr":{"type":"command","ns":"tracking.events",
 "command":{"find":"events","filter":{"accountId":"acc_7731","createdAt":{"$gte":{"$date":"2025-04-27T00:00:00Z"}},
 "status":{"$in":["in_transit","delivered","exception"]}},
 "sort":{"createdAt":-1},"limit":50},"planSummary":"IXSCAN { accountId: 1, status: 1, createdAt: 1 }",
 "keysExamined":181204,"docsExamined":181204,"hasSortStage":true,"nreturned":50,
 "durationMillis":2387}}

The part that annoyed us was planSummary. MongoDB was using our index. So why was it reading 181,204 documents to return 50, and why hasSortStage: true?

Reproducing it

The real query, run from mongosh against a staging restore of production:

db.events.find({
  accountId: "acc_7731",
  createdAt: { $gte: ISODate("2025-04-27T00:00:00Z") },
  status: { $in: ["in_transit", "delivered", "exception"] }
}).sort({ createdAt: -1 }).limit(50).explain("executionStats")

The endpoint always adds a status filter that the UI exposes as checkboxes. That detail turned out to matter.

What we ruled out

  • Missing index or wrong collection. The plan was an IXSCAN, not a COLLSCAN.
  • Cache pressure on the cluster. WiredTiger cache usage was steady around 70 percent and other queries on the same collection were fast.
  • Plan cache picking a stale plan. We ran db.events.getPlanCache().clear() and the planner chose the same plan again, with the same numbers.

Root cause

The collection had exactly one compound index with all three fields in it, { accountId: 1, status: 1, createdAt: 1 }. It was added a year earlier for a status report and everyone assumed it served this endpoint too, because "all the fields are in the index". The executionStats showed what that index actually did for this query:

executionStats:
  nReturned: 50
  executionTimeMillis: 2311
  totalKeysExamined: 181204
  totalDocsExamined: 181204
  executionStages:
    stage: 'SORT'                 <- blocking, in-memory sort
    sortPattern: { createdAt: -1 }
    memLimit: 104857600
    limitAmount: 50
    inputStage:
      stage: 'FETCH'
      inputStage:
        stage: 'IXSCAN'
        keyPattern: { accountId: 1, status: 1, createdAt: 1 }
        indexBounds:
          accountId: [ '["acc_7731", "acc_7731"]' ]
          status: [ '["delivered", "delivered"]', '["exception", "exception"]', '["in_transit", "in_transit"]' ]
          createdAt: [ '[new Date(1745712000000), new Date(9223372036854775807)]' ]

Because status comes before createdAt and the query asks for three statuses, the index returns entries grouped by status: all delivered events in date order, then all exception events, then all in-transit events. A single "newest first across all three" ordering does not exist in that index, so MongoDB read every matching key in the 30-day window, fetched every document, and sorted them in memory before applying limit: 50. Small accounts had a few hundred matches and nobody noticed. The largest account had 181,204.

What is happening under the hood

A compound index is a single sorted list of keys, ordered by the first field, then the second, and so on. MongoDB can return documents in index order without sorting only if, after fixing the equality fields, the next field in the index is the one you sort on.

MongoDB's guidance for building such indexes is the ESR rule:

Position Field kind Why
First Equality (accountId: "acc_7731") Narrows to one contiguous slice of the index
Second Sort (createdAt: -1) Inside that slice, keys are already in sort order
Third Range (createdAt >= ..., $in over many values, $ne, regex) Filters while walking in order, without breaking it

Put a range field before the sort field and the slice is no longer in sort order, so the engine must collect everything that matches the range and then run a blocking SORT stage. A blocking sort cannot stop early at limit: 50; it has to read all candidates first. That is why totalKeysExamined scaled with the size of the account, not with the page size.

A multi-value $in behaves like a range for ordering purposes. MongoDB can sometimes merge several sorted index scans (a SORT_MERGE stage) for a small $in placed before the sort field, but the planner does not always choose that, and it did not here. The ESR guideline itself says to treat $in over larger arrays like a range predicate.

Two numbers in executionStats are the fastest health check for any query:

  • totalKeysExamined / nReturned should be close to 1. Ours was 3,624.
  • totalDocsExamined / nReturned should also be close to 1. If keys are low but docs are high, the filter is being applied after FETCH instead of inside the index.

Environment

Component Version / value
Database MongoDB Atlas, 7.0.20, M40 replica set
Driver Node.js driver 6.16 via Mongoose 8.14
Collection tracking.events, 410 million documents, about 190 GB
Largest account about 2.1 million events in a 30-day window
Query equality on accountId, range on createdAt, $in on status, sort createdAt: -1, limit 50

Minimal reproduction

// mongosh, empty test database
db.ev.drop();
const docs = [];
for (let i = 0; i < 200000; i++) {
  docs.push({
    accountId: i % 10 === 0 ? "big" : "small" + (i % 50),
    status: ["in_transit", "delivered", "exception", "created"][i % 4],
    createdAt: new Date(Date.now() - i * 60000)
  });
}
db.ev.insertMany(docs);
db.ev.createIndex({ accountId: 1, status: 1, createdAt: 1 }); // range-ish field before sort

db.ev.find({ accountId: "big", status: { $in: ["in_transit", "delivered", "exception"] } })
  .sort({ createdAt: -1 }).limit(50)
  .explain("executionStats").executionStats.totalKeysExamined;

On our laptops this returned 15,000 keys examined for 50 documents.

Who is affected

Any MongoDB version, any driver. It shows up when a compound index was designed for one query shape and is reused by another, when filters are added later (status checkboxes, soft-delete flags), or when an ORM builds $in filters from UI state. Small accounts hide the problem completely; it only appears for the tenants with the most data.

The fix

We designed one index for this query using ESR, with the sort field directly after the equality field and the remaining filters after it:

db.events.createIndex(
  { accountId: 1, createdAt: -1, status: 1 },
  { name: "account_created_status_esr" }
);

status sits after the sort field, so MongoDB walks createdAt in descending order inside the account slice and checks status from the index key without fetching documents that do not match. createdAt: -1 matches the sort direction, though MongoDB can also walk an ascending index backwards for a single-field sort.

On Atlas we built it as a rolling index build from the UI so primaries were not affected. The status report keeps its own { accountId: 1, status: 1, createdAt: 1 } index, because that query really is equality on accountId and on a single status, then a sort, which is ESR for its shape.

Adding an index costs write throughput, so we looked for one to remove. A single-field { accountId: 1 } index was now a prefix of both compound indexes and therefore redundant. We checked its usage first:

db.events.aggregate([{ $indexStats: {} }]).forEach(s =>
  print(s.name.padEnd(40), s.accesses.ops, s.accesses.since.toISOString())
);

Then we hid it, which keeps it maintained but invisible to the planner, so un-hiding is instant if something regresses. After a quiet week we dropped it:

db.events.hideIndex("accountId_1");
// a week later, with no regressions
db.events.dropIndex("accountId_1");

Alternatives and trade-offs

  1. Use a hint(). Forces the right index without changing indexes, but it couples application code to an index name and silently becomes wrong when someone renames it. We used it only as a temporary patch during the index build.
  2. ERS instead of ESR. If the range is very selective (for example, the last 15 minutes), putting the range before the sort reads fewer keys and the in-memory sort is cheap. Our 30-day window was not selective, so ESR won.
  3. Bucket or archive old events. Moving events older than 90 days to an archive collection cut index size by a third. Helpful, but it would not have removed the blocking sort by itself.

How to test the fix

We wrapped the explain check in a script that runs in CI against a seeded MongoDB container:

// scripts/check-plans.js, run with: mongosh "$MONGO_URI" scripts/check-plans.js
const plan = db.events.find({
  accountId: "big",
  createdAt: { $gte: new Date(Date.now() - 30 * 86400000) },
  status: { $in: ["in_transit", "delivered", "exception"] }
}).sort({ createdAt: -1 }).limit(50).explain("executionStats");

const stats = plan.executionStats;
const json = JSON.stringify(plan.queryPlanner.winningPlan);
if (json.includes('"stage":"SORT"')) throw new Error("blocking SORT stage in winning plan");
if (stats.totalKeysExamined > stats.nReturned * 5) {
  throw new Error(`keys examined ${stats.totalKeysExamined} for ${stats.nReturned} docs`);
}
print("plan ok", stats.totalKeysExamined, stats.nReturned);
mongosh "mongodb://localhost:27017/tracking" scripts/check-plans.js

Confirming in production

After the index finished building we compared the same query on the largest account:

Metric Before After
totalKeysExamined 181,204 67
totalDocsExamined 181,204 50
Winning plan SORT over FETCH over IXSCAN LIMIT over FETCH over IXSCAN
executionTimeMillis 2,311 3
Endpoint p95 2.4 s 41 ms

The Atlas Profiler stopped listing the query within an hour, and the "Query Targeting: Scanned Objects / Returned" alert for the cluster dropped from above 2,000 to under 10.

Regression guard

  • check-plans.js runs in CI for the five busiest query shapes.
  • The Atlas "Query Targeting" alert threshold is set to 1,000 so a regression pages us before customers notice.
  • Every pull request that adds a filter to a repository method must include the explain output for the largest-tenant fixture.

Security implications

None beyond availability. A query that scales with tenant size is a cheap denial-of-service lever: anyone able to page through a large account could load the primary. The fix removes that. We also set maxTimeMS: 2000 on this find so a future bad plan fails fast instead of piling up connections.

Prevention checklist

  • Design compound indexes per query shape with Equality, then Sort, then Range.
  • Treat $in over many values, $ne, $nin and regex as range predicates when ordering fields.
  • Check totalKeysExamined / nReturned and look for a SORT stage in every new query's explain.
  • Hide an index before dropping it and watch $indexStats for a week.
  • Seed CI with at least one oversized tenant so plan regressions are visible.

References

Add a label

#mongodb #indexing #explain #query-performance #esr
Written by
Daniel Tran @fun_dev

I have spent most of my career on the side of software that pages people at night: payment integrations, web platforms with real traffic, CI/CD pipelines, Kubernetes clusters and the databases underneath them. Somewhere along the way I started keeping a notebook of every bug that cost more than an hour — the exact error, what we ruled out, the real root cause and how we proved the fix. Hibug is where those notes live. Every post follows the same path: Investigate, Explain, Fix, Verify — with the environment spelled out, the fix tested, and the security angle checked.

Advertisement

Comments

0

No comments yet. Be the first to comment!

Sign In to post a comment.