The symptom
p95 latency on your API doubled. The MongoDB host is not out of CPU, the disks are not full, and nothing was deployed. The slow part is somewhere inside mongod, and "somewhere" is not a diagnosis.
MongoDB gives you four different windows into query performance. They overlap just enough to be confusing. This post is the order to open them in, what each one can and cannot tell you, and the four root causes that account for almost every slow instance we have looked at.
Step 1: is it reads, writes, or commands? (serverStatus.opLatencies)
Before looking at any individual query, find out which *kind* of work got slower. serverStatus keeps cumulative latency histograms per operation class:
const s = db.serverStatus().opLatencies;
["reads", "writes", "commands"].forEach((k) => {
const mean = s[k].ops ? s[k].latency / s[k].ops / 1000 : 0;
print(k, "ops:", s[k].ops, "mean ms:", mean.toFixed(2));
});The counters are cumulative since the last restart, so a single reading is a lifetime average and hides the last ten minutes. Take two samples a minute apart and subtract: the delta is your live mean latency per op type.
- reads regressed, writes flat — a query shape lost its index, or the working set outgrew the cache (Step 3).
- writes regressed — look at WiredTiger write tickets and dirty cache before anything else (Step 4).
- everything regressed together — the instance is contended as a whole: global lock queue, ticket exhaustion, or a lagging secondary that is now taking reads.
This one check decides which of the next steps is worth your time.
Step 2: what is running right now? (currentOp)
db.currentOp({
active: true,
secs_running: { $gte: 1 },
op: { $ne: "none" }
}).inprog.forEach((o) => {
print(o.secs_running + "s", o.ns, o.op, JSON.stringify(o.command).slice(0, 200), "plan:", o.planSummary);
});Two fields matter more than the rest:
- planSummary —
COLLSCANon a collection with more than a few thousand documents is the finding.IXSCAN { field: 1 }on the wrong field is the same finding in disguise. - waitingForLock / lockStats — if the slow operation is not scanning but *waiting*, the problem is whoever holds the lock, not this query.
currentOp only shows operations in flight this instant. A query that takes 800 ms and runs a thousand times a minute will rarely be caught here. That is what the next two tools are for.
Step 3: which query shape is expensive over time? (profiler and $queryStats)
Turn on the profiler for one database at a slow-ms threshold you can defend, with a sample rate that will not fill system.profile in an hour:
use orders
db.setProfilingLevel(1, { slowms: 100, sampleRate: 0.2 });Then group the captured operations by shape rather than by literal values:
db.system.profile.aggregate([
{ $match: { millis: { $gte: 100 } } },
{ $group: {
_id: { ns: "$ns", op: "$op", plan: "$planSummary" },
n: { $sum: 1 },
avgMs: { $avg: "$millis" },
docsExamined: { $avg: "$docsExamined" },
docsReturned: { $avg: "$nreturned" }
}},
{ $sort: { n: -1 } },
{ $limit: 10 }
]);The ratio docsExamined / docsReturned is the number you want. A shape that examines 50,000 documents to return 20 is a missing or wrong index, no matter what the average latency says today. Fix that shape and your reads-latency line from Step 1 drops.
On MongoDB 7.0 and later, $queryStats gives you the same per-shape aggregate without writing to a profile collection and without the sampling gap:
db.getSiblingDB("admin").aggregate([
{ $queryStats: {} },
{ $sort: { "metrics.totalExecMicros.sum": -1 } },
{ $limit: 10 }
]);Both tools report the query *shape* (predicate keys, sort, projection), not the literal values, which is also what makes their output safe to ship to a ticket or a dashboard.
Step 4: is the storage engine the bottleneck? (WiredTiger tickets and cache)
If Step 1 said writes, or everything, start here rather than at the query.
const wt = db.serverStatus().wiredTiger;
const tickets = wt.concurrentTransactions;
print("write tickets in use:", tickets.write.out, "/", tickets.write.totalTickets);
print("read tickets in use:", tickets.read.out, "/", tickets.read.totalTickets);
const c = wt.cache;
print("cache fill:", (c["bytes currently in the cache"] / c["maximum bytes configured"] * 100).toFixed(1) + "%");
print("dirty:", (c["tracked dirty bytes in the cache"] / c["maximum bytes configured"] * 100).toFixed(1) + "%");
print("global lock queue:", db.serverStatus().globalLock.currentQueue.total);How to read it:
- write tickets near totalTickets — every additional write waits for a ticket. Latency spikes are step-shaped, not gradual. The cause is usually slow disk, oversized documents, or an update whose predicate is not indexed and holds its ticket for the whole scan.
- cache fill above 95% — the working set no longer fits, and reads are paying for eviction. More RAM or a smaller working set (drop unused indexes, archive cold documents).
- dirty above 20% — WiredTiger's own eviction trigger. Checkpoints are falling behind the write rate.
- global lock queue in the single digits, sustained — operations are serialising behind a lock holder. Go back to Step 2 and find who is holding it.
Step 5: replica-set specifics
Two checks that explain "slow" on a replica set when the primary itself looks fine:
rs.printSecondaryReplicationInfo(); // lag per secondary
rs.printReplicationInfo(); // oplog window in hoursA secondary lagging by more than about ten seconds will serve stale reads if your read preference allows it, and majority write concern will wait on it. If the oplog window is also shrinking, the lagging member is heading for a full resync, which is a much worse afternoon than the one you are having now.
The four root causes, ranked by how often they are the answer
1. A query shape with no usable index (Steps 2 and 3). Fix: create the index the shape needs, then confirm docsExamined drops to roughly docsReturned.
2. Working set larger than the WiredTiger cache (Step 4). Fix: memory, or shrink the working set.
3. Write-ticket exhaustion from slow storage or heavy updates (Step 4). Fix: reduce write concurrency at the pool, index the update predicate, check I/O wait on the host.
4. A lagging secondary taking reads or gating writes (Step 5). Fix: find why it lags (usually 2 or 3 on that member) before touching read preference.
Cursor leaks are a distant fifth: db.serverStatus().metrics.cursor.open.noTimeout above zero means something opened a cursor with noCursorTimeout and never closed it.
Doing this continuously instead of at 2 a.m.
Every check above is a point-in-time read. The slow query you catch tonight is the one that happened to be running when you looked; the one that costs you next week is not.
insightral watches MongoDB continuously, alongside Postgres, MySQL, SQL Server and Oracle, and turns the symptoms in this post into plain-language findings that say what is wrong, why it matters and what to do about it. Your data and credentials stay inside your network.
If you would like to see it on your own cluster, [book a demo](/demo) or [get in touch](/contact).