Performance Bottleneck Case Studies

Chapter 53: Performance Bottleneck Case Studies

Learning Objectives

• Diagnose and resolve real-world performance bottlenecks
• Apply the USE method and profiling tools to find root causes
• Understand N+1 query problems and slow query patterns
• Learn from GC pressure, connection pool, and CPU saturation cases

---

What is this? (Beginner On-Ramp)

Performance issue case studies explore mysterious slowness in production. They show the detective work required to find the single lock, bad database query, or network glitch that is causing an entire application to run slowly.

53.1 Case Study: N+1 Query Problem

    Scenario: API P99 latency: 8 seconds, was 200ms last week
    ─────────────────────────────────────────────────────────

    A new feature shipped: "Order History with Product Details"

    The Code:
    ──────────
    # (Python/SQLAlchemy)
    def get_order_history(user_id):
        orders = Order.query.filter_by(user_id=user_id).all()  # 1 query
        for order in orders:
            order.product = Product.query.get(order.product_id)  # N queries!
        return orders

    Database Load:
    • User has 100 orders
    • 1 (orders query) + 100 (product queries) = 101 queries per request!
    • At 500 RPS: 50,500 queries/second hitting DB

    Discovery:
    ──────────
    # pgbadger (PostgreSQL slow query log analysis):
    pgbadger /var/log/postgresql/postgresql-2024-01-15.log
    → "SELECT * FROM products WHERE id = $1": 45,000 calls/minute

    # pg_stat_statements:
    SELECT calls, mean_exec_time, query
    FROM pg_stat_statements
    ORDER BY calls DESC LIMIT 10;
    # calls=50000 mean_time=1.2ms query="SELECT * FROM products WHERE id=$1"

    Fix: Eager Loading (1 query instead of N+1)
    ───────────────────────────────────────────
    def get_order_history(user_id):
        orders = Order.query \
            .filter_by(user_id=user_id) \
            .options(joinedload(Order.product)) \  # JOIN once
            .all()
        return orders

    # SQL generated:
    # SELECT orders.*, products.*
    # FROM orders LEFT JOIN products ON orders.product_id = products.id
    # WHERE orders.user_id = ?
    # → 1 query total, regardless of order count!

    Result:
    Queries: 101 → 1 (99% reduction)
    P99 latency: 8s → 180ms
    DB CPU: 80% → 8%

---

53.2 Case Study: JVM GC Pressure

    Scenario: Java microservice with 10-second latency spikes every few minutes
    ────────────────────────────────────────────────────────────────────────────

    Pattern: Latency mostly fine at 50ms P99, but P999 = 10 seconds
    GC logs show: Full GC: 8-12 seconds every 3-5 minutes

    Investigation:
    ──────────────
    # Enable GC logging
    java -Xmx8g -Xms8g \
        -XX:+UseG1GC \
        -Xlog:gc*:file=/var/log/app/gc.log:time,uptime:filecount=5,filesize=20m \
        -jar app.jar

    # Analyze GC log
    java -jar gceasy-analyzer.jar gc.log
    → Heap usage: climbs to 95%, triggers Full GC
    → Full GC causes "Stop The World" pause = all threads frozen

    # Heap dump analysis
    jmap -dump:format=b,file=heapdump.hprof <pid>
    # Open in Eclipse MAT (Memory Analyzer Tool)
    → 4GB retained by: com.example.RequestCache (internal cache, unbounded!)

    Root Cause:
    An in-memory cache was growing unbounded — no eviction policy
    After 500K cached requests: cache = 4GB, heap pressure triggers Full GC

    Fixes:
    ────────
    # 1. Add eviction to cache (Guava Cache)
    Cache<Key, Value> cache = CacheBuilder.newBuilder()
        .maximumSize(10000)          # Max 10K entries
        .expireAfterWrite(5, MINUTES) # Evict after 5 minutes
        .build();

    # 2. Switch to ZGC (low-pause GC)
    java -XX:+UseZGC -XX:MaxGCPauseMillis=10 -jar app.jar
    # ZGC: pauses < 10ms even with 100GB heap

    # 3. Tune G1GC for low latency
    java -XX:+UseG1GC \
        -XX:MaxGCPauseMillis=50 \    # Target max 50ms pauses
        -XX:G1HeapRegionSize=32m \   # Larger regions
        -XX:InitiatingHeapOccupancyPercent=35 \  # GC earlier
        -jar app.jar

    Results:
    P999 latency: 10s → 50ms
    GC frequency: every 3 min → occasional
    GC pause: 8-12s → < 50ms

---

53.3 Case Study: Missing Database Index

    Scenario: Monthly report query takes 45 minutes, should take 30 seconds
    ─────────────────────────────────────────────────────────────────────────

    Query:
    SELECT user_id, SUM(amount), COUNT(*)
    FROM orders
    WHERE created_at BETWEEN '2024-01-01' AND '2024-01-31'
      AND status = 'completed'
    GROUP BY user_id;

    orders table: 50 million rows

    Investigation with EXPLAIN ANALYZE:
    ─────────────────────────────────────
    EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)
    SELECT user_id, SUM(amount), COUNT(*)
    FROM orders
    WHERE created_at BETWEEN '2024-01-01' AND '2024-01-31'
      AND status = 'completed'
    GROUP BY user_id;

    Output:
    Seq Scan on orders (cost=0.00..2234567.00 rows=50000000)
                        (actual time=0.043..2678432.123 rows=50000000)
      Filter: (created_at >= '2024-01-01' AND status = 'completed')
      Rows Removed by Filter: 48750000
    Planning Time: 0.5 ms
    Execution Time: 2678432.5 ms  ← 44 minutes!

    Problem: Sequential scan on 50M rows, filtering 98%!

    Solution: Composite Index
    ──────────────────────────
    CREATE INDEX CONCURRENTLY idx_orders_date_status
    ON orders (created_at, status)
    WHERE status = 'completed';  -- Partial index (only completed)

    # CONCURRENTLY: creates index without locking the table
    # Partial index: only indexes completed orders (smaller, faster)

    EXPLAIN after index:
    Index Scan using idx_orders_date_status on orders
      (cost=0.56..12543.00 rows=1250000)
      (actual time=0.043..8431.123 rows=1250000)
    Execution Time: 31542.3 ms  ← 31 seconds!

    Improvement: 2,678 seconds → 31 seconds (86x faster)

    Index Strategy Guidelines:
    ────────────────────────────
    # Columns to index:
    ✓ WHERE clause columns (filter columns)
    ✓ JOIN columns (foreign keys)
    ✓ ORDER BY columns
    ✓ GROUP BY columns (if also filtered)

    # Don't over-index:
    ✗ Every column (slows writes, wastes storage)
    ✗ Low-cardinality columns (boolean, status with 2 values)
    ✓ Use partial indexes for common filter patterns
    ✓ Use covering indexes (INCLUDE columns) for important queries

---

53.4 Case Study: Connection Pool Exhaustion

    Scenario: API intermittently returns 503, connection errors in logs
    ─────────────────────────────────────────────────────────────────

    Error: "too many connections" / "connection pool timeout"

    Investigation:
    ──────────────
    # Check active connections
    SELECT count(*), state, wait_event
    FROM pg_stat_activity
    GROUP BY state, wait_event
    ORDER BY count DESC;

    count  state   wait_event
    ─────────────────────────
    98     active  Lock      ← 98 queries waiting for locks!
    2      idle    (null)

    # Check for long-running transactions holding locks
    SELECT pid, now() - pg_stat_activity.query_start AS duration, query, state
    FROM pg_stat_activity
    WHERE (now() - pg_stat_activity.query_start) > interval '30 seconds'
    ORDER BY duration DESC;

    # Long-running query found:
    # SELECT * FROM orders FOR UPDATE (no timeout, waiting for row lock)
    # A job started at 14:00, still running at 14:45

    Root Cause Analysis:
    • Background job acquires SELECT FOR UPDATE on orders rows
    • Job runs slowly (full table scan, 45 minutes)
    • Other requests need to update those rows → wait in queue
    • All 100 DB connections busy waiting → new requests get 503

    Fixes:
    ──────

    # 1. Statement timeout (kill queries that run too long)
    # postgresql.conf:
    statement_timeout = '30s'   # Kill queries > 30s

    # Per-connection:
    SET statement_timeout = '5000';  # 5 seconds for this session

    # 2. Lock timeout (don't wait forever for locks)
    lock_timeout = '5s'   # Give up on lock after 5 seconds

    # 3. Right-size connection pool
    # Per Little's Law: connections = RPS × avg_query_time
    # 500 RPS × 0.02s avg = 10 connections minimum
    # Add 50% headroom: 15 connections per app instance

    # PgBouncer connection pooler (transaction mode)
    pool_mode = transaction    # Connection returned to pool after each statement
    max_client_conn = 1000     # Many app connections
    default_pool_size = 20     # Few actual DB connections
    # → 1000 app connections → 20 actual PostgreSQL connections

    # 4. Fix the background job
    # Use cursor-based pagination instead of holding all rows:
    for order in Order.query.yield_per(1000):  # 1000 at a time, don't hold lock
        process(order)

---

53.5 Case Study: CPU Saturation from Inefficient Serialization

    Scenario: API server at 95% CPU despite low request rate (50 RPS)
    ──────────────────────────────────────────────────────────────────

    Service: Go REST API returning large JSON responses

    Profiling with perf:
    ─────────────────────
    go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30

    (pprof) top 20
    Showing nodes accounting for 87.40%, 98.05% of 30s total
        flat  flat%   sum%        cum   cum%
      14.12s 47.07% 47.07%     14.12s 47.07%  encoding/json.(*encodeState).marshal
       8.34s 27.80% 74.87%      8.34s 27.80%  encoding/json.reflectValue
       3.21s 10.70% 85.57%      3.21s 10.70%  runtime.mallocgc

    JSON encoding consuming 85% of CPU!

    Root Cause:
    Each API response was serializing 5MB of nested JSON
    using Go's reflect-based encoding/json (slow)

    Fixes (in order of impact):
    ─────────────────────────────

    # 1. Use faster JSON library
    # github.com/goccy/go-json or github.com/bytedance/sonic
    # Drop-in replacement, 3-5x faster

    import gojson "github.com/goccy/go-json"
    gojson.Marshal(data)  # Instead of encoding/json.Marshal(data)

    # 2. Add Response Caching (best fix)
    # Most responses were identical for same parameters
    # Redis cache: cache JSON responses for 30 seconds

    # 3. Pagination (reduce response size)
    # Return 100 items per page instead of all 5000 items
    # Response size: 5MB → 100KB (50x smaller)

    # 4. Protocol Buffers instead of JSON (binary)
    # protobuf: 3-10x smaller + 5-10x faster than JSON
    # Better for internal service communication

    Results:
    CPU: 95% → 15%
    P99 latency: 2.1s → 210ms
    Throughput: 50 RPS → 600 RPS (same hardware)

---

53.6 Performance Investigation Checklist

# ── First 60 Seconds ──────────────────────────────────────
uptime                     # Load average
free -h                    # Memory
iostat -x 1 3              # Disk I/O
mpstat -P ALL 1 3          # Per-CPU utilization
ss -s                      # Network connections summary

# ── Application Level ─────────────────────────────────────
# Check error rates (RED method)
# Check P99 latency (is it spiky or sustained?)

# ── Database ──────────────────────────────────────────────
# Active queries and wait events
# pg_stat_statements (top queries by total_time)
# Long-running transactions
# Index hit ratios

# ── Profiling ─────────────────────────────────────────────
perf record -g -p <pid> sleep 30
perf report --stdio | head -40

# Flame graph
perf script | stackcollapse-perf.pl | flamegraph.pl > flame.svg

---

53.7 Summary

Bottleneck	Signal	Tool	Fix
N+1 queries	Slow API, pg_stat_statements	pgbadger, explain	Eager loading
GC pressure	Latency spikes, GC logs	GC logs, heap dump	Cache eviction, ZGC
Missing index	Seq scan, slow queries	EXPLAIN ANALYZE	Composite/partial index
Connection pool	503s, connection errors	pg_stat_activity	PgBouncer, timeouts
Slow serialization	CPU 100%, profiler	pprof, perf	Faster library, caching

---

Next Chapter: Chapter 54: Kubernetes Failure Case Studies

Prerequisites

Chapter 23 (Performance Analysis).

---

Deep Dive Case Study: The Thundering Herd and Connection Pool Exhaustion

The Incident

A highly anticipated flash sale went live. At exactly 12:00 PM, traffic spiked 50x above normal baseline. The web tier successfully auto-scaled horizontally (HPA) from 10 to 100 pods.

The Failure

Each of the 100 web pods was configured to maintain a connection pool of 50 connections to the PostgreSQL database. 100 pods * 50 connections = 5,000 concurrent connections. The PostgreSQL instance was only tuned to handle max_connections = 1000.

The database rejected the new connections. The web pods threw HTTP 500 errors. Users repeatedly hit refresh, creating a “Thundering Herd” that kept the database overwhelmed.

The Fix

Horizontal scaling for stateless apps is easy; scaling stateful databases is hard.

1. PgBouncer (Connection Pooling): Introduced PgBouncer as a middleware layer. The 100 web pods connect to PgBouncer, which multiplexes thousands of incoming lightweight connections onto a small number of actual PostgreSQL backend connections.
2. Circuit Breakers & Jitter: Implemented the circuit breaker pattern in the web tier. If the DB fails, the web tier immediately returns a cached or friendly error page instead of hammering the DB. Retries were implemented with randomized exponential backoff (“jitter”) to prevent synchronized retry waves.

---

Advantages & Disadvantages

Advantages: Shows how to use the USE/RED methods in practice to find hidden bottlenecks. Disadvantages: Finding the root cause often requires deep knowledge of application code, not just OS.

---

Common Mistakes

• Tuning the database when the bottleneck is the network.
• Throwing more hardware (CPU/RAM) at an architecture problem (e.g., N+1 query problem).
• Using average response times instead of percentiles (P99) to measure performance.

---

Troubleshooting

Symptom	Cause	Diagnosis	Fix
CPU usage is low but latency is high	Lock contention, I/O waits, or network latency	perf record -g; check for futex calls	Profile application locks; analyze database slow query logs
Application throughput flatlines despite scaling	Connection pool exhaustion or single-threaded bottleneck	Check active DB connections; check per-core CPU usage	Increase connection pool size; refactor for concurrency

---

Hands-on Lab

Objective: Identify a bottleneck using the USE method.

# 1. Check Utilization, Saturation, and Errors for CPU
uptime
vmstat 1 5

# 2. Check for Disk
iostat -xz 1 5

# 3. Check for Network
sar -n DEV 1 5

---

Exercises

1. Explain how to diagnose a memory leak in a Java or Python application running on Linux. What metrics would indicate a leak?
2. Analyze a scenario where a database connection pool is set to 5, but the application receives 100 concurrent requests/second. What are the symptoms?

---

Revision Notes

• The USE Method (Utilization, Saturation, Errors) is the fastest way to identify system bottlenecks.
• N+1 query problems in ORMs (Object-Relational Mappers) are a leading cause of database performance issues.
• Garbage collection (GC) pauses can cause massive tail latency spikes in Java/Go/Python apps.
• Lock contention (threads waiting for a mutex) looks like low CPU usage but terrible performance.

---

Further Reading

• Systems Performance by Brendan Gregg

---

Related Chapters

• Chapter 23 — Performance Analysis

---

Last Updated: July 2026