Finding Bottlenecks

The breakpoint test is done: POST /holds keeps its p99 under 300 ms up to about 1 100 requests per second, and the on-sale needs 4 500. Now what? Adding pods blindly may change nothing — or make things worse. This page is about the step between measuring and fixing: reading the results correctly, locating the limiting resource, seeing which code or query consumes it, and changing one thing at a time until the bottleneck sits where you want it.

Reading the results

The stepped curve

A breakpoint test that holds each rate for a couple of minutes produces one point per step: offered load, achieved throughput, p99 and errors. The table and the plot below are typical (synthetic data with noise):

Three regions are visible, and each has a name you should use in reports:

• Up to the knee (≈ 1 100 req/s): achieved = offered, p99 within the SLO. This is the usable capacity of this deployment.
• Between the knee and the maximum: achieved still ≈ offered, but the p99 breaks the SLO — the system is working, just too slowly; queues are building.
• Past the maximum (≈ 1 250 req/s): achieved throughput falls while offered keeps growing, requests time out, errors appear. The system is saturated and, here, retrograde: overload makes it less efficient (timeouts, retries, lock convoys).

The capacity you report is the knee: "one inventory deployment of 4 pods sustains 1 100 holds/s within the SLO; it saturates at ~1 250 and degrades beyond".

Symptoms and what they usually mean

A catalogue of common bottlenecks

Profiling: from "which resource" to "which code"

Metrics tell you that inventory spends its time waiting or burning CPU; a profiler tells you which code does it. Modern profilers are sampling profilers: many times per second they record the stack trace of each thread, and the code that appears in many samples is where the time goes. The overhead is low enough (typically a few percent) to profile under load, even in production.

Two kinds of profile answer different questions:

• On-CPU profiles sample only threads that are running. They find CPU-heavy code — serialization, regexes, hashing, TLS.
• Off-CPU / wall-clock profiles sample threads whatever they are doing, including waiting for locks, sockets and pools. When CPU is low but latency is high — the common case — only a wall-clock profile shows where the time goes.

Reading a flame graph

A flame graph draws the sampled stacks as nested boxes¹:

• each box is a function (a stack frame); the box below it is its caller;
• the width is the share of samples in which the function was on the stack — wider means more time;
• the x-axis is not time: frames are sorted alphabetically to merge identical stacks;
• look for wide boxes near the top (where time is actually spent) and for unexpectedly wide subtrees.

Reading this wall-clock profile of POST /holds top-down: almost all the time is inside TransactionTemplate.execute — and inside it, a third of the samples wait on a socket read inside SeatRepository.lockSeats (the database is making us wait for row locks), more than a quarter wait on a socket read inside PricingClient.quote (an HTTP call inside the transaction, holding the connection and the locks), and almost a quarter wait in HikariPool.getConnection (pool exhaustion, caused by the two previous items). JSON and logging, the usual suspects, are thin slivers. A CPU flame graph of the same service would have shown mostly JSON and logging, and pointed at the wrong fix.

async-profiler for the JVM

async-profiler is a low-overhead sampling profiler for Java that avoids the safepoint bias of older JVM profilers and produces flame graphs directly². It attaches to a running JVM:

# distroless images have no shell: attach an ephemeral debug container that shares
# the pod's process namespace, built from an image that contains async-profiler
kubectl debug -it inventory-7f9c-x2k8p --image=<your-debug-image-with-async-profiler> --target=inventory

asprof -d 30 -e cpu   -f /tmp/cpu.html   1    # on-CPU samples, 30 s, JVM is PID 1
asprof -d 30 -e wall  -t -f /tmp/wall.html 1  # wall-clock, split by thread: includes waiting
asprof -d 30 -e lock  -f /tmp/lock.html  1    # contended Java monitors and locks
asprof -d 30 -e alloc -f /tmp/alloc.html 1    # allocation hot spots (GC pressure)

Run the profiler while the load test is at the plateau — a profile of an idle service shows only idle code. If perf_events are not permitted in the container, -e itimer (or ctimer) is a CPU-sampling fallback. The JDK's built-in Java Flight Recorder is the alternative with no extra tool (jcmd 1 JFR.start duration=60s filename=/tmp/inventory.jfr settings=profile); open the recording in JDK Mission Control or convert it to a flame graph with async-profiler's converter.

py-spy for Python

The assistant service is Python (FastAPI). py-spy is a sampling profiler that reads the interpreter's memory from outside the process — no code changes, no restart³:

py-spy top    --pid 1                                   # live "top" of Python functions
py-spy record --pid 1 --duration 30 -o cpu.svg          # flame graph (SVG) of running code
py-spy record --pid 1 --duration 30 --idle -o wall.svg  # include idle/waiting threads
py-spy dump   --pid 1                                   # current stack of every thread, once

In a container py-spy needs the SYS_PTRACE capability (add it to the debug container, not to the application). For asyncio code, remember that waiting coroutines are not threads: a wall-clock view of the event loop shows where the loop is blocked — the classic bug being a synchronous call (a blocking HTTP client, CPU-heavy parsing) inside an async def handler.

Continuous profiling

Profiling only during incidents means you have no "before" to compare with. Continuous profiling samples every instance all the time at low frequency and stores the profiles like metrics (Grafana Pyroscope, cloud profilers; OpenTelemetry is adding profiles as a fourth signal). It enables differential flame graphs — this version vs the previous one — which make performance regressions in a canary obvious.

Database bottlenecks

The database is the most common bottleneck of a system like BoxOffice, because it is the one component that is hard to scale horizontally and that every write must reach.

Which queries?

Start from the aggregate, not from a guess. The pg_stat_statements extension records statistics for every normalized query:

SELECT left(query, 70)                         AS query,
       calls,
       round(total_exec_time)                  AS total_ms,
       round(mean_exec_time::numeric, 2)       AS mean_ms,
       round(100 * total_exec_time / sum(total_exec_time) OVER (), 1) AS pct
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;

Sort by total time, not mean: a 2 ms query called 3 000 times per second costs more than a 2 s report run once an hour.

Why is it slow? EXPLAIN ANALYZE

EXPLAIN shows the plan the optimizer chose; EXPLAIN (ANALYZE, BUFFERS) executes the query and reports real times, real row counts and pages read⁴. The seat-map query of the on-sale:

EXPLAIN (ANALYZE, BUFFERS)
SELECT id, section, row_label, seat_number, price_cents
FROM seats
WHERE event_id = 4242 AND status = 'AVAILABLE'
ORDER BY section, row_label, seat_number
LIMIT 8;

Limit  (cost=187432.10..187432.12 rows=8 width=40) (actual time=412.551..412.555 rows=8 loops=1)
  Buffers: shared hit=2112 read=59861
  ->  Sort  (cost=187432.10..187507.10 rows=30000 width=40) (actual time=412.549..412.551 rows=8 loops=1)
        Sort Key: section, row_label, seat_number
        Sort Method: top-N heapsort  Memory: 26kB
        ->  Seq Scan on seats  (cost=0.00..186832.00 rows=30000 width=40) (actual time=0.031..405.127 rows=31480 loops=1)
              Filter: ((event_id = 4242) AND (status = 'AVAILABLE'::text))
              Rows Removed by Filter: 5968520
Planning Time: 0.142 ms
Execution Time: 412.601 ms

How to read it, bottom-up (the innermost node runs first):

• Seq Scan with Rows Removed by Filter: 5968520 — PostgreSQL read all 6 million seats of all events to keep 31 480. That is the problem.
• Buffers: … read=59861 — about 60 000 pages (8 KB each, ≈ 470 MB) came from disk or the OS cache rather than PostgreSQL's buffer cache. Under load, this is I/O saturation.
• Sort … top-N heapsort — sorting 31 480 rows to keep 8; cheap here, but avoidable.
• Compare estimated rows=30000 with actual rows=31480: close, so statistics are fine. A large mismatch (100× off) would point at stale statistics (ANALYZE) or correlated columns.

A partial index that matches both the filter and the sort order lets PostgreSQL read the first 8 available seats directly, in order:

CREATE INDEX CONCURRENTLY seats_available_idx
    ON seats (event_id, section, row_label, seat_number)
    WHERE status = 'AVAILABLE';

Limit  (cost=0.43..9.87 rows=8 width=40) (actual time=0.041..0.058 rows=8 loops=1)
  Buffers: shared hit=5
  ->  Index Scan using seats_available_idx on seats  (cost=0.43..35392.11 rows=30000 width=40) (actual time=0.040..0.055 rows=8 loops=1)
        Index Cond: (event_id = 4242)
Planning Time: 0.210 ms
Execution Time: 0.079 ms

From 412 ms to 0.08 ms and from ~62 000 pages to 5. CONCURRENTLY builds the index without blocking writes — essential on a live table. (Indexes are not free: each one slows down writes and uses memory; index what the workload model says is hot.)

-- Lab 6: indexes for the listing "upcoming events in a city, soonest first".
-- Walk events in starts_at order and stop after one page, instead of sorting 20,000 rows:
CREATE INDEX events_starts_at_idx ON catalog.events (starts_at, id);
-- Count/filter the events of a city's venues without reading the whole table:
CREATE INDEX events_venue_starts_at_idx ON catalog.events (venue_id, starts_at);
CREATE INDEX venues_city_idx ON catalog.venues (city);

Lock contention and hot rows

When everyone wants the same seats, transactions queue for row locks. Find who waits for whom:

SELECT pid,
       pg_blocking_pids(pid)        AS blocked_by,
       wait_event_type, wait_event,
       now() - query_start          AS waiting_for,
       left(query, 60)              AS query
FROM pg_stat_activity
WHERE cardinality(pg_blocking_pids(pid)) > 0;

Three changes reduce contention, in order of effort:

1. Keep transactions short. Never call another service (pricing, payment) while holding a transaction: compute the price before BEGIN, call the payment provider after COMMIT (with an outbox or a saga — see Messaging — patterns).

2. Do not fight for the same row. When the fan asks for "2 seats in section A", any two free seats will do. SKIP LOCKED lets concurrent transactions take different free rows instead of queuing on the first one:

   BEGIN;
   SELECT id FROM seats
   WHERE event_id = 4242 AND section = 'A' AND status = 'AVAILABLE'
   ORDER BY row_label, seat_number
   LIMIT 2
   FOR UPDATE SKIP LOCKED;
   UPDATE seats
      SET status = 'HELD', held_by = $1, hold_expires_at = now() + interval '10 minutes'
    WHERE id = ANY($2);
   COMMIT;
   

3. Control admission. If 50 000 fans try to hold seats in the same second, no locking strategy makes PostgreSQL happy. A waiting room admits fans at the rate the inventory can absorb — turning contention into an orderly queue (Messaging — queues).

Sizing the connection pool

A connection pool can be a bottleneck in both directions: too small and requests wait for a connection; too large and the database spends its time switching between hundreds of sessions, fighting over locks and memory. Size it with Little's Law — connections needed = throughput × time each request holds a connection:

The first fix is not a bigger pool — it is holding the connection for less time. Then size for the database's capacity: PostgreSQL works best with a number of active connections in the order of a few times its CPU cores (HikariCP's often-quoted starting point is connections ≈ cores × 2 + effective spindles)⁵. Twenty pods × a pool of 20 = 400 connections is far beyond that; put PgBouncer in transaction-pooling mode between the pods and the database so that hundreds of client connections share a few dozen server connections. And fail fast:

spring:
  datasource:
    hikari:
      maximum-pool-size: 10
      minimum-idle: 10            # a fixed-size pool: no ramp-up during the spike
      connection-timeout: 2000    # wait at most 2 s for a connection (the default is 30 s)

; PgBouncer: thousands of client connections, a few dozen real PostgreSQL connections.
[databases]
boxoffice = host=db port=5432 dbname=boxoffice

[pgbouncer]
listen_addr = 0.0.0.0
listen_port = 6432
auth_type = scram-sha-256
auth_file = /etc/pgbouncer/userlist.txt
admin_users = boxoffice

; transaction pooling: a server connection is lent for ONE transaction, then returned
pool_mode = transaction
; real connections to PostgreSQL per (database, user) pair
default_pool_size = 20
; client connections PgBouncer accepts (all services and replicas together)
max_client_conn = 1000
; protocol-level prepared statements work in transaction mode (PgBouncer >= 1.21)
max_prepared_statements = 200
ignore_startup_parameters = extra_float_digits,options

One change at a time: an optimization log

Keep a log of every run: what changed, the new knee, and what saturated next. A bottleneck removed reveals the next one; the goal is not "no bottleneck" (there is always one) but the bottleneck in the right place with enough capacity. The log below is illustrative of a typical campaign on POST /holds:

After run 6 the bottleneck is deliberate: the waiting room's admission rate, set below the database's knee. Scaling further would require partitioning inventory by event or venue (Databases — partitioning) — a much bigger change, now justified by numbers.

Try it: the monolith scenario (one app server and one PostgreSQL, the breakpoint profile) produces the first two lines of such a log in a few minutes. Run it as it is and open the Report: the bottleneck is app, already 86 % busy at about 430 req/s, and the system breaks at about 590 req/s. Change one thing — select app and raise its replicas to 6 — and run again: the breaking point jumps to about 2,520 req/s, and the bottleneck moves to db, 87 % busy at about 2,180 req/s. Now change the wrong thing: 12 replicas instead of 6. The breaking point stays at about 2,520 req/s while the monthly cost goes from about 1,170 to 1,890 USD — adding capacity to a component that is not the bottleneck buys nothing.

How it connects

flowchart LR
    CURVE["stepped curve<br/>and symptoms"] --> RES["which resource?<br/>USE → Methodology"]
    RES --> PROF["which code? flame graphs,<br/>async-profiler, py-spy"]
    RES --> DBQ["which query? pg_stat_statements,<br/>EXPLAIN ANALYZE"]
    DBQ --> IDX["indexes, N+1<br/>→ Databases models"]
    DBQ --> LOCK["hot rows, SKIP LOCKED<br/>→ Databases transactions"]
    DBQ --> POOL["pool sizing by Little's Law,<br/>PgBouncer"]
    RES --> CACHE["low hit ratio, stampede<br/>→ Caching failure modes"]
    RES --> DEP["slow dependency<br/>→ Reliability patterns"]
    PROF --> LOG["one change at a time:<br/>the optimization log"]

Palette components: app (CPU, GC, thread pools, serialization) · sql (indexes, locks, connection pools) · cache (hit ratio, hot keys, stampedes) · queue (taking contended writes off the request path) · thirdparty (slow dependencies) · tracing (N+1 queries show up as dozens of identical spans) and metrics (pool and throttling counters). Scenarios: monolith (breakpoint profile: find the first resource to saturate), read-heavy-cache, flash-sale (hot seat rows). Continues in: Databases — transactions, Databases — partitioning, Caching — failure modes, Messaging — queues and pub/sub, Reliability — patterns, Capacity planning.