A console.log Was My Kafka Bottleneck

I expected the ceiling to be Kafka, or the network, or something respectably distributed. It was a log statement.

While building Event Lab, a single consumer on a single partition kept showing 0–400 messages of lag every two seconds at only a few hundred msgs/sec. A simple parse-and-process consumer should handle 10,000+. Something was wrong, and it wasn't where I looked first.

The false leads

The honest version of debugging is that you fix several real things on the way to the one that actually matters. Before I found the real issue, I cleaned up a few genuine bugs in the lag calculation:

• Null/undefined consumer offsets when the consumer hadn't committed yet.
• A topic-name mismatch (events-input vs events.input) in the pause endpoint.
• Negative-lag scenarios that should warn rather than silently pass.

All real. None of them explained the throughput ceiling.

The actual culprit: logging every message

The clue, in hindsight, was that the ceiling was suspiciously round. Not 187 or 213 messages per second, but a wall right at about 200 every time, no matter the target. Flat ceilings like that don't come from a distributed system buckling under load. They come from something synchronous firing once per message.

The consumer logged every message it processed. That single JSON-parse-plus-log was capping throughput around 200 msgs/sec.

An I/O reality check

The numbers make it obvious once you line them up:

| Operation | Rough latency | Relative cost | | --- | --- | --- | | Memory operation | ~100 ns | 1× | | SSD write | ~100 µs | ~1,000× | | Console write | ~1–10 ms | ~10,000–100,000× |

At 200 msgs/sec, logging every message meant ~200 console writes per second, and the CPU spent most of its time waiting on I/O rather than doing work.

The fix: batch the logging

The mental model that made it click for me: picture a worker on an assembly line boxing items. Boxing is fast. But if the worker has to walk across the warehouse to write each item on a clipboard before boxing the next one, the walking sets the pace, not the boxing. console.log was the walk across the warehouse. The fix is to stop walking every time and instead jot a tally every ten thousand items.

this.messagesProcessed++
// Log once every 10,000 messages instead of every message
if (this.messagesProcessed % this.logInterval === 0) {
  log(`Consumer processed ${this.messagesProcessed} messages`)
}

Logging once per 10,000 messages instead of once per message cut I/O operations by ~99.5%. The lag disappeared and the consumer could handle 10,000+ msgs/sec.

What I'd want a reader to take away

A few things I want to hold onto from this one:

• I/O is the hidden bottleneck. Even a "fast" console.log destroys throughput at scale.
• Batching is leverage. Reducing I/O frequency 1000× unlocked a 50×+ throughput improvement.
• Know your throughput envelope. Parse-and-log: 10–20K msgs/sec in Node. DB writes: 500–5K. Heavy transforms: 100–1K.
• A single partition means a single consumer. No horizontal scaling without more partitions, a separate lesson.

Profile before you optimize, always. But when throughput hits a flat, suspicious ceiling and the numbers refuse to add up, check for hidden I/O before you blame the broker. It's almost never the exciting thing.

Part of the Event Lab case-study series.