Govind
← all posts

A 40% CPU regression, found with perf and one bad assumption

2 min read performance · linux

A routine dependency bump in tailpipe — our Kafka → ClickHouse ingestion pipeline — added 40% CPU across the consumer fleet. No new features, no config changes. Three services, one shared library, one very expensive assumption.

The bad assumption

The bump replaced a hand-rolled FNV-style hash in the partitioner with the standard library's SipHash. On a microbenchmark, SipHash was faster per call. The author of the bump — me — extrapolated from there.

That extrapolation was wrong, and perf showed why in one trace:

$ perf record -F 999 -g -- ./tailpipe consume --topic events
$ perf report --stdio --no-children --sort overhead,symbol
  41.7%  tailpipe  [.] siphash13::Hasher::write
  12.3%  tailpipe  [.] dashmap::try_result::try_result
   9.8%  tailpipe  [.] alloc::alloc::Global::alloc

A third of all CPU time was inside the hash. But not because the hash was slow in isolation — because of what we were hashing.

What was actually happening

The FNV-style hash consumed keys incrementally as they streamed in from the network. SipHash's default entry point takes a whole slice, so the code collected each key into a Vec<u8> first. Two extra copies per message, plus an allocation, plus the old map was now doing more work per bucket because SipHash's output distribution changed which buckets collided.

At 1M events/sec, "two extra copies per message" is 2M allocations per second. The microbenchmark missed it because the microbenchmark only measured the hash function. Production measured the hash function plus my buffer management, and my buffer management was losing.

The fix

Keep the incremental API and give up on SipHash for this path:

  1. Bishop Fox's incremental hash crate, fed straight from the network buffer.
  2. Pre-size the DashMap to the new expected concurrency (it was still sized for the pre-SipHash collisions).
  3. Add the real workload to CI as a criterion benchmark with allocation counting — the number that would have caught this is allocations/message, not ns/hash.

CPU came back under the original baseline, and the pipeline held a new peak — 1M events/s at under 2s end-to-end lag.

The generalizable lesson: microbenchmarks tell you what a function costs. They cannot tell you what calling it forces you to build around it.