Jack Thompson

Triage profiler output and pick the one fix worth trying first

Paste cProfile, py-spy or Chrome profiler output and get the top hotspots by self time, an Amdahl-style ceiling, and one change to try first.

At a glance

Best for: Developers with a slow endpoint or job and a profile in hand, who need to know where the next hour of optimization should go.
Tested on: Claude · Opus 5.5
You fill in: whatprofiletarget
You get: Top 3 by self time (tottime) recv_into : 6.34 s (65%) parse_pattern : 0.88 s (9%) execute : 0.41 s, tied with writerow at 0.41 s (4% each) What kind… (full result below)

coding

debugging

data-analysis

Prompt

Here's profiler output from a slow {{what}}. Help me decide where to spend the next hour.

Profile:
{{profile}}

Fast enough means: {{target}}

1. Separate self time from total (cumulative) time, and name the top 3 hotspots by self time.

1. For each one, say whether it's (a) unnecessary work, (b) necessary work done inefficiently, or (c) waiting on I/O, locks or GC. Say what in the profile tells you: call counts, the ratio of self to total time, or the function name.

1. Estimate the ceiling: if the biggest hotspot dropped to near zero, what's the best-case total? Can the target be reached by fixing it alone? Show the arithmetic.

1. Recommend one change to try first, with code if you can, and the measurement that would prove it worked.

1. List anything else worth fixing to reach the target, in order.

Don't suggest micro-optimizations for anything under 5% of the total time.

Fill in

{{what}}: What is slowe.g. Django endpoint that exports 20,000 orders to CSV
{{profile}}: The profiler output, pastede.g. cProfile output sorted by cumulative time
{{target}}: What "fast enough" means, as a numbere.g. Under 2 seconds for 20k rows

Example input

what: Django 5 endpoint that exports 20,000 orders to CSV
target: under 2 seconds for 20k rows
profile:
```
         4180331 function calls in 9.812 seconds
   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.004    0.004    9.812    9.812 orders/export.py:12(export_orders_csv)
    20000    0.061    0.000    6.944    0.000 django/db/models/fields/related_descriptors.py:226(__get__)
    20001    0.412    0.000    7.187    0.000 django/db/backends/utils.py:98(execute)
    20001    6.338    0.000    6.338    0.000 {method 'recv_into' of '_socket.socket' objects}
    20000    0.090    0.000    2.401    0.000 orders/export.py:40(format_row)
   140000    0.198    0.000    1.902    0.000 babel/numbers.py:664(format_currency)
   140000    0.884    0.000    1.244    0.000 babel/numbers.py:1150(parse_pattern)
    20001    0.410    0.000    0.410    0.000 {method 'writerow' of '_csv.writer' objects}
```

2.3k0

Generated Outputs (1)

2 hours ago

Claude

Opus 5.5

2 hours ago

Generated Output

1. Top 3 by self time (tottime)

1. recv_into: 6.34 s (65%)

1. parse_pattern: 0.88 s (9%)

1. execute: 0.41 s, tied with writerow at 0.41 s (4% each)

2. What kind of cost each one is

• recv_into: (c) waiting, caused by (a) unnecessary work. It's socket reads from the database. The giveaway is the call count: 20,001 queries for one export. related_descriptors.get is called 20,000 times with 6.94 s cumulative. That's order.customer lazy-loading one customer per row, the classic N+1.

• parse_pattern: (a) unnecessary work. 140,000 calls means the currency format pattern is parsed again for every money value (7 per row). The pattern never changes.

• execute / writerow: necessary work at a reasonable cost. Below the 5% line, so leave them.

3. Ceiling
The N+1 path costs 6.94 s. Replacing it with one joined query costs about the same as the initial query, say 0.1–0.3 s.
9.81 − 6.94 + 0.3 ≈ 3.2 s best case. That misses the 2 s target on its own. Add the formatting fix below (2.40 s down to roughly 0.5 s) and you reach about 1.3 s, which meets it.

4. Try first: fetch customers in the same query
`python
orders = (
Order.objects.filter(created_at__range=(start, end))
.select_related("customer") # one JOIN instead of 20,000 queries
.only("id", "created_at", "total", "tax", "customeremail", "customername")
.iterator(chunk_size=2000)
)
`
Proof it worked: rerun the profile. execute should drop from 20,001 calls to 1 (or a handful with chunking), and related_descriptors.get cumulative time should fall to milliseconds. In tests, wrap the export in assertNumQueries(1) so the N+1 can't come back.

5. Next, in order

1. Stop re-parsing the currency pattern. If the CSV is machine-read, write plain decimals (f"{amount:.2f}") and let the spreadsheet format them. If it needs locale formatting, parse the pattern once outside the loop and reuse it, instead of calling format_currency 140,000 times.

1. Re-profile. If you're still above 2 s, look at whatever is now on top rather than guessing. The ordering usually changes once the N+1 is gone.

Why it works

Splitting self time from cumulative time is the skill most people skip when reading profiles. It shows that recv_into is where time goes, but the call count shows why. The (a)/(b)/(c) classification forces a diagnosis (unnecessary vs inefficient vs waiting) before any fix. The ceiling calculation with visible arithmetic is the most useful step: it showed the obvious N+1 fix alone couldn't hit the 2 s target, so the second fix was planned up front. The 5% floor prevents busywork on things that don't matter.

When not to use it

A single profile of a single run misleads when the slowness is intermittent: cold caches, lock contention, noisy neighbors or GC pauses under load. Use repeated measurements or production tracing (APM, pg_stat_statements) for those. Sampling profilers on async code can also attribute waiting time strangely, so confirm the diagnosis with a before/after timing, not just the profile.

Comments (0)

No comments yet. Be the first to share your thoughts!