Profiling a Slow Endpoint: Flame Graph to Fix, On-CPU vs Off-CPU

Define the slow endpoint before you profile it

Profiling a slow endpoint means measuring where a single request's time actually goes, then attributing it to specific code paths, queries, or waits. In a monolith, that job usually belongs to the backend or platform engineers who own the service. They are the people who can read the code, change the queries, and see the production telemetry.

Write the problem statement first

"Checkout is slow" is not something you can profile. A useful statement names the route and method, the percentile, the affected inputs, and the shape of the latency. For example: POST /orders p99 rose from 400 ms to 2.5 s for tenants with more than 5,000 line items, consistently since Tuesday's deploy.

The percentile choice changes the investigation. A slow p50 means the common path is expensive. A slow p95 or p99 with a healthy median points toward specific inputs, lock contention, GC pauses, or a cold cache. Intermittent latency needs a different approach than consistent latency, and so does latency that shows up only for large tenants.

Rule out capacity before profiling code

Check the infrastructure signals first. If every endpoint slowed down at the same time as a CPU saturation spike, a connection-pool exhaustion event, or a noisy neighbor on the database host, you have a capacity or infrastructure problem. A profiler will mostly show you threads waiting.

Reproduce in staging, not on your laptop

Use a staging environment with production-like data volume and realistic concurrency. Local reproductions are misleading because they hide the conditions that cause the slowness:

• Small datasets keep result sets short.
• Warm caches skip expensive reads.
• Single-user traffic never contends for locks or pool connections.
• A database on localhost answers in microseconds.

With near-zero database latency, 300 sequential queries look free. That is exactly how N+1 patterns go unnoticed until they reach production.

Who should use this workflow

The workflow in this article is aimed at engineers who can act on what a profile shows:

• Backend engineers who own the endpoint. They can change the queries, the serialization code, and the request handler, so they can turn a flame graph into a fix.
• Platform or SRE engineers. They run the tracing pipeline and the profilers, and they can tell an application problem apart from an infrastructure one.
• On-call engineers doing follow-up after an incident. Once traffic is stable, they need to find out why one route degraded.
• Engineers reviewing a performance-sensitive change. They can compare profiles before and after a deploy to catch a regression early.

You need three things: access to traces for the service, permission to run a profiler against a staging or production process, and enough familiarity with the code to map stack frames back to the source. If you lack production access, pair with someone who has it. A profile you can't relate to the code, or a codebase you can't profile, only gives you half the picture.

When to profile a slow endpoint

Profile when the slowness is specific and reproducible, and when the cause isn't obvious from existing telemetry. Typical triggers:

• A tail-latency alert for one route, such as p95 or p99 crossing its objective, while other routes stay healthy.
• A latency step change that lines up with a deploy, a schema change, or a large customer's data growth.
• Latency that grows with input size, such as more line items, more tenants, or larger pages.
• A trace with large unexplained gaps between spans, or with many repeated short spans.
• CPU or database load on the service rising faster than its traffic.

Hold off in some situations:

• During an active incident. Mitigate first by scaling, shedding load, or rolling back. Profile after the system is stable.
• When every endpoint is slow at once. That points to capacity or a shared dependency, as described above.
• When the endpoint is unbounded by design. Fix the design first, for example by adding pagination.

The final section covers these trade-offs in more detail.

How the workflow works

The method narrows the search in stages. Each stage uses a cheaper, broader signal to decide where to point the next, more detailed one.

1. Metrics locate the problem. Per-endpoint latency percentiles tell you which route is slow, for which inputs, and since when. That gives you the problem statement.
2. Traces locate the time within a request. A distributed trace records spans for the handler, database queries, and outbound calls, each with a start time and a duration. Adding up the span durations shows whether the request spends its time in application code, in the database, in downstream services, or in gaps that no span covers.
3. Profilers locate the code. A sampling profiler periodically records the call stack of the process's threads. It aggregates the samples into a flame graph, where wider frames appeared in more samples. On-CPU profiling samples threads that are running. Wall-clock profiling samples all threads. Off-CPU profiling records where threads blocked and for how long. The trace tells you which of these modes you need.
4. The fix targets the dominant cost. Typical fixes are batching N+1 queries, hoisting repeated work out of loops, reducing serialization, or moving work off the request path.
5. Verification closes the loop. Re-profile under the same conditions, compare query counts and tail latency, and add a regression test so the fix stays in place.

Each stage costs more effort than the previous one but gives a more precise answer. Running them in order means you only profile a request after the trace has shown where to look.

Use APM traces to decide where to look

An N+1 pattern that looks free locally gets expensive once it meets a production database across a network, where each round trip costs real time.

A trace tells you which part of that time to profile. For the slow request, sum span durations into four groups: application code, database, external HTTP calls, and time no span accounts for. The last group matters most. A gap between spans means the process was doing something nobody instrumented, or waiting on something nobody measured.

CopyGET /orders/42                      [=========================== 480 ms]
  auth.check                        [==] 22 ms
  db.query SELECT orders              [=] 9 ms
  db.query SELECT items WHERE id=?      [] 3 ms
  db.query SELECT items WHERE id=?       [] 3 ms
  db.query SELECT items WHERE id=?        [] 3 ms
  ... 61 more, near-identical ...
  (no spans)                                       [............] 170 ms
  http.post pricing-service                                     [==] 40 ms

The ladder of short, repeated queries is the N+1 signature. Each query looks harmless, and only the count shows the cost. The 170 ms gap is a separate problem, and the trace cannot explain it.

Gaps usually come from auto-instrumentation blind spots. These include custom serialization or computation loops, work handed to background threads or executors where trace context is not propagated, and database or cache drivers the agent does not hook. Waiting on a lock or a connection pool also shows up as empty time.

To close a gap, wrap the suspect block in a manual span with a descriptive name and attributes such as row count, as in the example below. Redeploy and check whether the gap becomes a named span. If it does, you know whether you need an on-CPU or an off-CPU profiler.

Copyfrom concurrent.futures import ThreadPoolExecutor

from opentelemetry import context, trace

tracer = trace.get_tracer("orders.service")
executor = ThreadPoolExecutor(max_workers=4)


def build_order_response(order, items):
    # Name the block that showed up as an empty gap in the waterfall.
    with tracer.start_as_current_span("orders.serialize_response") as span:
        # Record sizes so a slow span can be tied to input volume.
        span.set_attribute("app.order.item_count", len(items))
        payload = [serialize_item(item) for item in items]
        span.set_attribute("app.order.payload_items", len(payload))
        return payload


def submit_price_refresh(order_id):
    # Capture the request's trace context before handing off to another thread.
    parent_ctx = context.get_current()
    return executor.submit(_refresh_prices, parent_ctx, order_id)


def _refresh_prices(parent_ctx, order_id):
    # Re-attach the context so this span joins the request trace
    # instead of becoming an orphan or not being recorded at all.
    token = context.attach(parent_ctx)
    try:
        with tracer.start_as_current_span("orders.refresh_prices") as span:
            span.set_attribute("app.order.id", order_id)
            recompute_prices(order_id)
    finally:
        context.detach(token)

Using the OpenTelemetry Python API to wrap an uninstrumented serialization loop in a manual span and to propagate trace context into a thread-pool worker, so time that showed up as a gap becomes a named span.

On-CPU vs off-CPU: choose the right profiler first

A sampling profiler interrupts the process at a fixed interval and records the current stack of each thread it is watching. Merge enough of those stacks and you get a picture of where time goes. The key question is which threads get sampled. A CPU profiler samples only threads that are running. Most slow endpoints are not running. They are waiting on a query, a lock, a connection pool, or a downstream call. A CPU-only profile will show you the small amount of work the request does and point at the wrong code.

Let the trace choose the mode. If the slow span was mostly a database or HTTP call, use wall-clock or off-CPU profiling. If an unexplained gap turned out to be compute, use on-CPU profiling.

Sampling is statistical. Events shorter than the sampling interval, or ones that happen rarely, may never be captured. Narrow frames can still drive tail latency. Collect enough samples under realistic load before you trust the shape.

Runtime behaviour also distorts profiles:

• JIT warm-up: early samples are inflated by interpreter and compiler frames.
• GC pauses: these show up as runtime frames, or as gaps with no stack.
• Interpreter vs native stacks: an interpreted runtime may show only interpreter loop frames unless the profiler can resolve language-level stacks.

How to read a flame graph without fooling yourself

The x-axis is not time. A flame graph merges identical stacks and sorts frames alphabetically or by name, so left-to-right order means nothing. A frame's width is its share of the collected samples. A frame twice as wide was on the stack twice as often during the profiling window. If you need to see when something happened within a single request, use a flame chart, which keeps samples in time order. Most profilers offer both views, and screenshots often confuse them.

Read top-down for cost. Look for wide plateaus near the top of stacks. These are frames that spend their own time rather than delegating to children, and they are where cycles or waits are actually spent. A wide frame lower down only tells you that its descendants are expensive.

Common monolith culprits have recognizable shapes:

• N+1 queries: a loop or collection-iteration frame with ORM and database-driver frames stacked repeatedly beneath it. In an off-CPU profile they appear as socket-read waits.
• Serialization of large object graphs: wide encoder frames, often recursing deeply as they walk lazily loaded associations.
• Repeated work in loops: regex compilation, config or feature-flag lookups, or reflection appearing under a per-item frame instead of once at startup.
• Lock or pool contention: off-CPU time in mutex, condition-variable, or connection-pool acquire frames.
• Synchronous downstream calls: HTTP client frames blocked on network reads.

The widest frame is not always a defect. If it is necessary work, such as rendering a report users asked for, micro-optimizing it rarely helps. The fix is architectural: caching, pagination, precomputation, or moving the work off the request path.

Fixing N+1 queries and other common culprits

Most slow endpoints, though, are not doing necessary work. They are doing the same small piece of work many times.

N+1 queries

The classic shape in a flame graph is a wide frame under the ORM's query method, made of hundreds of identical narrow calls. The before code loads 200 orders, then accesses order.customer inside the loop, which triggers one query per row. Illustrative estimate, not a measurement: assuming 200 rows and a 2 ms network round trip per query, that is roughly 400 ms of database time spent mostly waiting. A single batched query costs one round trip plus slightly more server work.

There are three common fixes:

• Eager loading tells the ORM to fetch the association up front, either with a join or with a second query.
• A batched IN query collects the IDs, issues WHERE id IN (...) once, and builds a lookup map.
• A dataloader-style layer collects lookups within a single request tick and resolves them together. It is useful when the calls are spread across resolvers or helper functions that a single loop cannot reach.

Hoisting repeated work

The same pattern shows up on-CPU. A regex compiled inside a loop, a formatter rebuilt for each row, or configuration re-parsed on every call should each be created once, outside the loop.

Trade-offs

Eager loading can overcorrect. Joins duplicate parent rows, memory grows with the association size, and payloads swell with data the client never uses. Batching and caching add code paths, staleness, and invalidation bugs. A cache can also mask the real problem: the endpoint looks fast until the cache goes cold under load.

Copyimport re
import sqlite3

def orders_with_names_slow(conn: sqlite3.Connection, orders):
    result = []
    for order_id, customer_id in orders:
        row = conn.execute(
            "SELECT name FROM customers WHERE id = ?", (customer_id,)
        ).fetchone()
        result.append((order_id, row[0] if row else None))
    return result

def orders_with_names_batched(conn: sqlite3.Connection, orders):
    ids = sorted({customer_id for _, customer_id in orders})
    if not ids:
        return []
    # Databases cap bound parameters per statement; chunk ids for very large sets.
    placeholders = ",".join("?" * len(ids))
    rows = conn.execute(
        f"SELECT id, name FROM customers WHERE id IN ({placeholders})", ids
    ).fetchall()
    names = dict(rows)  # lookup map: customer_id -> name
    return [(order_id, names.get(customer_id)) for order_id, customer_id in orders]

def extract_skus_slow(lines):
    return [m.group(1) for line in lines
            if (m := re.compile(r"SKU-(\d+)").search(line))]

SKU_RE = re.compile(r"SKU-(\d+)")

def extract_skus_fast(lines):
    return [m.group(1) for line in lines if (m := SKU_RE.search(line))]

Before/after Python using the standard sqlite3 module: an N+1 loop of per-row lookups becomes a single batched IN query with a lookup map, and a regex compiled inside a loop is hoisted to a module-level constant.

Verify the fix and guard against regression

Re-profile under the same conditions that produced the original flame graph: the same request mix, concurrency, and a dataset of similar size and shape. An N+1 fix tested against a table with ten rows proves nothing, because the original cost grew with row count. Put the before and after profiles side by side, or generate a differential flame graph. Frames that shrank confirm the fix. Frames that grew show where the cost moved, such as a larger result set being deserialized in one place. Also check query counts per request directly. If the fix worked, the count should be constant regardless of how many items the response contains.

In production, watch p95 and p99 rather than the mean. Averages absorb a slow tail, and that tail is often what users notice and what saturates connection pools.

To guard against regression, add a test that calls the endpoint with a fixture containing many related records, counts the SQL statements issued during the request, and fails if the count exceeds a fixed bound. This catches the most common way N+1 returns: someone adds a field to the serializer that triggers lazy loading.

Keep low-rate sampling profiling or sampled tracing running in production, and alert on tail latency per endpoint. Both cost CPU and memory. Full tracing of every request also adds export bandwidth and storage, so sample deliberately. Redact sensitive values from span attributes, and record parameterized SQL rather than statements with literal values inlined.

Copyimport contextlib

import pytest
from sqlalchemy import event

MAX_QUERIES = 4  # Bound chosen from the fixed endpoint: auth + orders + items + count


@contextlib.contextmanager
def count_queries(engine):
    statements = []

    def on_execute(conn, cursor, statement, parameters, context, executemany):
        statements.append(statement)  # Keep SQL text so a failure shows what ran

    event.listen(engine, "before_cursor_execute", on_execute)
    try:
        yield statements
    finally:
        event.remove(engine, "before_cursor_execute", on_execute)


@pytest.mark.parametrize("n_orders", [5, 200])
def test_orders_endpoint_query_count_is_bounded(client, engine, seed_orders, n_orders):
    # `client`, `engine`, `seed_orders` are project fixtures (test client,
    # SQLAlchemy engine, factory that creates orders with line items).
    seed_orders(count=n_orders, items_per_order=3)

    with count_queries(engine) as statements:
        response = client.get("/api/orders?limit=500")

    assert response.status_code == 200
    assert len(response.json["orders"]) == n_orders  # Make sure all rows were serialized
    assert len(statements) <= MAX_QUERIES, (
        f"{len(statements)} queries for {n_orders} orders:\n" + "\n".join(statements)
    )

A pytest regression test that counts SQL statements issued during one request using SQLAlchemy's before_cursor_execute event and fails if the count exceeds a fixed bound at both small and large fixture sizes.

Alternatives and the impact on cost and engineering time

Profile-driven tuning has its own costs. You have to set up tracing, the profiler adds nonzero overhead when it samples in production, and someone has to interpret the output. Each alternative below avoids some of that upfront cost but takes on a different risk.

Defer profiling during an active incident. Scale or shed load first. Skip it entirely when an endpoint is unbounded by design, such as one that returns every row: paginate that first, because profiling will only confirm it. Fixes also carry upkeep. Batch loaders change query shape and partial-failure handling. Caches add invalidation paths and memory pressure. A profile tells you whether that complexity is justified.

The trace-first workflow saves time mainly through targeting. A trace tells you whether the request is on-CPU or waiting before you spend effort on a fix, so you don't optimize code that isn't the bottleneck.

Illustrative estimate (assumed numbers, not a benchmark):

Expected cost of a fix = cost per attempt ÷ probability the attempt hits the real bottleneck.

Assume each attempt costs 2 days:

• Guessing, with an assumed 1-in-3 hit rate: 2 ÷ 0.33 ≈ 6 days.
• Tracing and profiling cost 1 day, with an assumed 0.9 hit rate: 1 + 2 ÷ 0.9 ≈ 3.2 days.

Substitute your own attempt cost and hit rates to compare the two for your system.

How OneEnv can help

Disclosure: OneEnv is the product behind this blog.

OneEnv (oneenv.io) is a workspace-based governance platform for the things services share — environment variables, database structure, API routes and validation rules. A change to a shared value is staged on a branch, reviewed once, and then every affected service explicitly approves or rejects it before it goes live, so you can see who a change touches before it ships instead of finding out in production.

Applied to profiling slow endpoint flame graph, this is where it helps:

Saves time

• Every service that inherits a shared value is listed in one place, so nobody searches repos and chats to find out who is affected.
• One review per branch replaces coordinating each team separately; each service still keeps its own approve/reject.
• Changing a shared variable is one edit and one review instead of editing every service's .env by hand.

Saves cost

• Fewer production incidents and rollbacks caused by a shared value, route or column changing under a consumer unannounced.
• Less duplicated configuration to maintain: one shared definition inherited by many services.
• A wrong or stale value is caught at review time by the services it affects, not by a failed deploy.
• OneEnv has a free plan (1 workspace, unlimited services and members, full governance), so trying it costs nothing.

These are qualitative benefits, not measured results — how much you save depends on how many services share the value.

Want to try it? Start at oneenv.io.