How Flame Graphs Cut 17% CPU at 200k QPS: Logging Stack Traces & Map Scans

Context and Goal

The commission-reduction service sits on the driver order-matching critical path. During holiday peaks it runs on 1,000+ instances (4c8g) handling ~200k QPS. While the instance count is justified by complex downstream calls, it amplifies cluster pressure: service discovery, connection management, Kafka consumer-group rebalances, and release churn. A previous over-scale event triggered continuous Kafka rebalances that took a broker offline. The optimization goal was to squeeze maximum CPU efficiency from each instance — without altering billing logic or compromising stability — to reduce instance count and create headroom for future growth.

Profiling: Assumptions vs. Data

The team initially assumed CPU was dominated by the commission calculation itself and by unavoidable SOA serialization/RT overhead. Production flame graphs captured with async-profiler told a different story: actual computation accounted for only ~3% of CPU; the vast majority was spent building the request context before calculation. Aggregating samples across the entire flame graph exposed two dominant hotspots:

Custom Logger.info calls — 12.4% of total CPU samples — each synchronously capturing a full stack trace just to emit a file-name:line-number prefix.

Fee-item lookup via Map.values().stream().filter(...) — repeated full scans of a ConcurrentHashMap because the query key ( code) was not the map key.

Both root causes were well-defined, low-risk, and verifiable in isolation, so they became the optimization focus.

Issue 1: Logging Stack-Trace Overhead

Phenomenon

Flame graphs showed Throwable.fillInStackTrace and getStackTraceElement matching the width of the custom logger, together consuming 12–13% of process CPU.

Root Cause

Every info call invoked Thread.currentThread().getStackTrace() to obtain the third stack frame for a file/line suffix. This forces the JVM to walk the entire Java stack, materialize StackTraceElement[], and allocate objects — all on the business thread — even though the log is later written asynchronously. The cost scales linearly: total ≈ QPS × logs-per-request × average-stack-depth.

Fix

Removed the synchronous stack capture entirely; the logger now delegates directly to the underlying SLF4J logger:

public static void info(Logger paramLogger, String format, Object... arguments) {
    paramLogger.info(format, arguments);
}

Issue 2: Fee-Item Cache Full-Table Scan

Phenomenon

Flame graphs for fee-item initialization showed repeated ConcurrentHashMap traversal and Stream filtering. The cache was a Map<Long, OriginalBillItem> keyed by an internal ID, but lookups were by business code:

public static OriginalBillItem get(String code) {
    return CACHE.values().stream()
        .filter(item -> item.getCode().equals(code))
        .findAny()
        .orElse(null);
}

Batch queries compounded the problem: after finding one item, the code iterated the category list again, yielding O(n²) behavior.

Root Cause

The query field was not a map key. With ~100 fee items, worst-case comparisons reached ~10,000 per request. Switching to a for-loop only reduces constants; the algorithmic fix is to index by the lookup field.

Fix

Added a secondary ConcurrentHashMap<String, OriginalBillItem> keyed by code:

private static final Map<String, OriginalBillItem> CACHE_BY_CODE =
    new ConcurrentHashMap<>(320);

public static OriginalBillItem get(String code) {
    return CACHE_BY_CODE.get(code);
}

Single lookup drops from O(n) to average O(1); batch getAll() improves from O(n × (n + m)) to O(n).

Validation: Controlled Ablation Experiments

To prove causality and isolate each change, four variants were load-tested on identical hardware and traffic:

Baseline

Stack-trace capture disabled only

Fee-item cache indexed only

Both optimizations enabled

Single-node results (CPU %, RT ms):

Baseline: 65%, 46 ms

No stack trace: 57%, 46 ms

Indexed cache: 58%, 46 ms

Both: 48%, 46 ms

Each optimization independently shaved ~7–8 percentage points; combined they delivered a 17-point drop. RT remained flat because the removed work was pure CPU computation, not downstream wait time.

Flame-Graph Re-verification

Fee-item get() CPU share under extreme load fell from ~12% to ~0.2%, confirming elimination of the full scan.

Production Verification

Deployed August 6. Comparing same-instance metrics from August 5 (pre) and August 12 (post) showed clear CPU reduction with no regression in RT, GC, or heap. The service subsequently handled the 2026-09-30 peak with CPU staying below 30% (a 10-point drop at equal scale).

Reusable Lessons

Measure first. Intuition misled the team; production sampling and controlled experiments are the only reliable guide.

Audit core-path "micro" actions. Logging, allocations, and collection scans look cheap per call but amplify under massive QPS.

Map ≠ O(1) lookup. Only when the query field is the map key does the hash index apply; iterating values() is still a full scan.

Algorithmic complexity beats syntax tweaks. Replacing Stream with for-loop only cuts constants; removing nested scans changes O(n²) to O(n).

Validate each optimization in isolation. Fixed environment, single-variable changes, and ablation comparisons separate real gains from noise.

Performance tuning is not a one-off project. At this scale, every verified micro-optimization compounds into tangible capacity headroom, enabling the next growth wave without proportional hardware spend.