DEV Community

Saqib Ameen Subhan
Saqib Ameen Subhan

Posted on

mtools does not parse MongoDB 4.4+ JSON logs. So I built mdbkit.

#mongodb #opensource #database #cli

If you have operated MongoDB for any length of time, you know mtools. For years it was how we all read production logs. mloginfo, mplotqueries, and a slow query was suddenly visible.

Then MongoDB 4.4 changed the log format to structured JSON, and the log tools stopped understanding what they were reading.

That was six years ago. The support issue was opened in June 2020 and it is still open. We are on 8.0 now, and a lot of us have been getting by with grep, jq pipelines held together by hope, and a certain amount of squinting.

I got tired of it and built the replacement. It is called mdbkit, it is MIT licensed, and it is public as of this week.

Try it in sixty seconds without touching a cluster

This is the part I would want first if this were someone else's tool.

pip install --upgrade mdbkit
# macOS ships no pip: brew install pipx && pipx install mdbkit

mdbkit demo -o demo.log
mdbkit queries demo.log
Enter fullscreen mode Exit fullscreen mode

mdbkit demo generates a realistic MongoDB log containing an actual incident. No cluster, no connection string, nothing of yours involved. You get to judge the tool on a problem you can inspect before you point it at anything that matters.

Here is what queries gives you on that demo log:

saqib@MacbookPro mongodb_logs % mdbkit queries demo.log
== mdbkit queries (slow query shapes) ==
lines: 1,004  parsed: 1,004  unparsed: 0  span: 2026-07-01T08:00:00+04:00 -> 2026-07-01T09:29:44.615000+04:00

namespace      op         count  cumMs  mean   max    docsEx      scan     plan            shape
-------------  ---------  -----  -----  -----  -----  ----------  -------  --------------  ---------------------------------------------
shop.events    aggregate  53     5.6m   6.3s   8.9s   47,170,000  98889:1  COLLSCAN+SORT   {tenantId:eq, ts:gte} sort:{ts:-1}
shop.orders    find       89     2.4m   1.6s   2.4s   11,125,000  2976:1   COLLSCAN+SORT   {createdAt:gt, status:eq} sort:{createdAt:-1}
shop.sessions  find       58     34.7s  597ms  888ms  2,784,000   155:1    IXSCAN{active}  {active:eq, lastSeen:gt} sort:{lastSeen:-1}
shop.products  update     42     25.7s  612ms  799ms  2,268,000   54000:1  COLLSCAN        {sku:eq}
shop.users     find       56     6.7s   119ms  139ms  56          1:1      IXSCAN{email}   {email:eq}

cumMs  = total wall time accumulated across ALL occurrences (not one query)
docsEx = total documents examined across all occurrences
scan   = docsExamined per returned doc (high = index missing or weak)
plan   = most common query plan; COLLSCAN/+SORT = index needed
         empty plan (?) = plan not present in log (below slowms threshold)
next   : mdbkit advise <log> [--ns <namespace>] for index candidates
Enter fullscreen mode Exit fullscreen mode

That is not a screenshot I curated. demo is seeded, so those two commands produce that exact table on your machine too, down to the last digit. It behaves the same on my laptop, on yours, and on a conference projector.

The column that matters is the scan ratio. It is documents examined against documents returned, per query shape. A shape sitting at 98889:1 is reading roughly ninety nine thousand documents to hand back one. A shape at 1:1 is doing exactly the work it needs to.

That single ratio is most of slow query triage. Everything else is detail.

The workflow I actually use

Three commands, in order.

First, find the shape that is hurting.

mdbkit queries /var/log/mongodb/mongod.log
Enter fullscreen mode Exit fullscreen mode

Slow operations grouped by query shape rather than listed individually. This matters more than it sounds. A log with 40,000 slow query lines is usually eight or nine distinct shapes repeating, and the one costing you the most is rarely the one that appears most often.

Then, ask what would fix it.

mdbkit advise /var/log/mongodb/mongod.log
Enter fullscreen mode Exit fullscreen mode

This proposes candidate indexes based on the shapes it observed. More on how that works below, because it is the part people should be suspicious of.

And when something has already gone wrong, build the timeline.

mdbkit triage /var/log/mongodb/mongod.log
Enter fullscreen mode Exit fullscreen mode

Elections, rollbacks, stalls, connection storms, in order, with timestamps. When you are twenty minutes into an incident and someone senior is asking what happened, a timeline you did not have to assemble by hand is worth a great deal.

The log cannot tell you everything

There is one failure mode a mongod log structurally cannot explain: the log simply stops, then starts again a minute later with no error in between.

The process was killed before it could write anything. That answer lives in the system log, one line up from where you were looking.

mdbkit triage mongod.log --oslog /var/log/syslog
Enter fullscreen mode Exit fullscreen mode 
[CRIT] Process start(s) in window: mongod startup marker at 09:14:35
[CRIT] System: oom-kill: The kernel OOM killer terminated a task.
         1 occurrence (last at 09:14:03). Processes: mongod.
         next: This explains an unexplained restart in the log above.
Enter fullscreen mode Exit fullscreen mode

oslog reads /var/log/syslog or /var/log/messages and looks for the things that end database processes: OOM kills, file descriptor limits, segmentation faults, I/O errors, filesystems remounted read only, systemd service exits. Used with triage, the unexplained restart gets matched to the kernel line that caused it.

On journald systems there is no text log to read, and mdbkit will not run commands on your behalf, so it prints the journalctl invocation for you to capture and feed back in.

There is also ftdc, which decodes diagnostic.data offline. Every one of your nodes has been recording CPU, cache, queue depth and disk every second since the day you installed it, whether or not you run any monitoring. Plus serverstatus for making sense of a serverStatus dump, and compare for answering whether the index you added last week actually helped.

It never connects to your database

No driver. No URI. No network code anywhere in it.

mdbkit reads log files you hand it. It is strictly read only. Where an action would help, it prints the command for you to review and run yourself, rather than running anything on your behalf.

I built it this way because I would not run a stranger's tool on a production host, and I do not expect you to either. So rather than asking you to trust me, the README shows you how to verify it independently. grep the source for socket and driver imports. Run it under strace and watch it make no network calls. It takes about a minute and you should do it.

Zero runtime dependencies too, nothing in the supply chain beyond the Python standard library. That was a deliberate constraint and it cost me some convenience, but a tool that ships onto database servers should not drag a dependency tree behind it.

The index advice is rules, not AI

I gave a talk at the Dubai MongoDB User Group recently about how confidently language models describe a MongoDB that no longer exists. They will happily reference plannerVersion, a field removed in 5.0. They do not know about EXPRESS stages in 8.0. And more importantly, they cannot know your cardinality, your write mix, or what is currently sitting in your plan cache, because none of that is in your query text.

So mdbkit's index advice is deterministic. Rules over observed query shapes. The same log always produces the same recommendation.

Every suggestion comes with the evidence it reasoned from, a confidence level, and how to validate it before you act. It says candidate, never command. And it will never tell you to drop an index, because deciding an index is unused requires knowing about traffic that a log file cannot show you.

That is a deliberately narrow promise. I would rather it be right about a small thing than confident about a large one.

What would help most

Two things, and they are both easy for you and hard for me.

Real world log lines that parse incorrectly. Every MongoDB deployment logs slightly differently, and I have only seen the estates I have worked on. If mdbkit chokes on a line, that line is the most useful thing you can send me.

Index advice that is wrong or unhelpful. If it suggests something you know is a bad idea for your workload, I want to know why, because that is a rule that needs fixing.

Every release so far has come from someone doing exactly that. An FTDC decode that took twenty five minutes and pinned a CPU. A crash on a batched write. A restart with no explanation, which is why oslog exists at all.

Supports MongoDB 4.4 through 8.0. Python 3.8+.

Free, MIT, and built because the gap annoyed me for long enough.

If you liked this, I also wrote about deleting 2TB from a live MongoDB cluster without anyone noticing and why I take down a healthy primary on purpose.

Top comments (0)