A couple of years ago our team spent two weeks rewriting queries for a slow order search endpoint. We added indexes, denormalised a column and cut the SQL time by half. The endpoint got 8% faster. When someone finally attached a profiler, 55% of the wall time was a structured logger serialising the full request context, including a 2 MB object graph, on every call. The SQL was never the main problem. We had guessed, and guessed wrong.
This guide is the workflow we use now on every performance ticket: capture a profile in the real environment, read it as a flame graph, change one thing, and measure again. It covers the three runtimes we run in production (PHP, Node.js and Python) with tools that are free and work in containers. You do not need to know profiler internals; you need to know which command to run and what the picture means.
Decide what you are measuring first
Before opening any tool, write down three things in the ticket:
- The metric. p95 latency of one endpoint, CPU seconds per job, or throughput at a fixed CPU.
- The baseline. A number measured the same way you will measure afterwards.
- The scenario. Which request, which data size, which environment. Profiling the home page of an empty dev database tells you nothing about a customer with 40,000 orders.
Then decide whether the problem is CPU or waiting. A CPU profile shows where code runs; it can hide time spent waiting on the database, network or locks. Wall-clock profiles include waiting. Most of the tools below can do both; pick deliberately.
How to read a flame graph
A flame graph stacks call frames: each bar is a function, the bar under it is its caller, and the width is how much of the sampled time that function (and everything it called) was on the stack.
- The x-axis is not time order. Bars are sorted alphabetically or merged, so left versus right means nothing.
- Look for wide plateaus: a wide bar with little on top means the function itself is spending the time ("self time").
- A wide bar with a tall tower above it is just a caller; the cost is somewhere up the tower.
- Narrow but numerous towers that all end in the same function (for example, a JSON encoder) can add up; use the tool's search to highlight a function and see its total share.
- Icicle graphs are the same thing upside down. Many tools let you switch.
Our rule of thumb: anything under 5% of total width is not worth optimizing until the big bars are gone.
PHP: SPX for quick answers, Xdebug for detail
SPX is a lightweight profiler extension with a built-in web UI that shows a timeline and a flame graph. It is the fastest way to profile one request in a dev or staging container.
; conf.d/spx.ini (staging only, never on a public production host)
extension=spx.so
spx.http_enabled=1
spx.http_key="change-me-dev-key"
spx.http_ip_whitelist="127.0.0.1"
Open http://localhost:8080/?SPX_KEY=change-me-dev-key&SPX_UI_URI=/ through a port-forward, enable
profiling in the control panel, then load the slow page. The report lists the request with wall time,
CPU time and memory, and the flame graph is one click away.
Xdebug in profile mode writes Cachegrind files, which are heavier but include exact call counts. Use trigger mode so you only profile the requests you ask for:
xdebug.mode=profile
xdebug.start_with_request=trigger
xdebug.output_dir=/tmp/xdebug
curl -s -o /dev/null "https://staging.example.com/orders/search?q=lamp&XDEBUG_TRIGGER=1"
ls /tmp/xdebug # cachegrind.out.<pid>
Open the file in QCacheGrind or KCachegrind and sort by "Self". Xdebug adds significant overhead, so trust its proportions, not its absolute times.
Node.js: --cpu-prof and DevTools
Node has a built-in sampling profiler. Start the process with it, run your load, and stop the
process cleanly; a .cpuprofile file is written on exit:
node --cpu-prof --cpu-prof-dir=./profiles dist/server.js &
npx autocannon -c 20 -d 30 http://localhost:3000/api/orders/search?q=lamp
kill -INT %1
Open the file in Chrome DevTools (Performance panel, load profile) or drag it into speedscope,
which renders flame graphs and a "left heavy" view that merges identical stacks. For a running
production process you cannot restart, open the inspector on demand with kill -USR1 <pid>, connect
DevTools through an SSH tunnel to the inspector port, and record for 30 seconds. Never expose the
inspector port publicly.
Watch out for (garbage collector) and (program) bars. A wide GC bar means allocation pressure;
the fix is usually upstream (creating fewer large objects), not in GC flags.
Python: py-spy without touching the code
py-spy samples a running Python process from the outside, with low overhead, so it is safe on
production with care. It needs the SYS_PTRACE capability in containers.
# Live, top-like view of where time goes right now
py-spy top --pid 4127
# 60-second flame graph as an interactive SVG
py-spy record --pid 4127 --duration 60 -o order-search.svg
# Speedscope format to compare runs side by side
py-spy record --pid 4127 --duration 60 --format speedscope -o order-search.json
Add --idle when you suspect waiting rather than computing; by default py-spy drops idle threads,
which hides time blocked on sockets. For async apps, look for the event loop thread being busy in
synchronous code, a common cause of everything slowing down at once.
Measure the change, not the feeling
After each change, rerun the same scenario and compare numbers, not impressions:
hyperfine --warmup 3 --runs 20 \
'curl -s -o /dev/null https://staging.example.com/orders/search?q=lamp'
For services, use the load test that produced the baseline and compare p50, p95 and CPU per request. Keep the before and after flame graphs in the ticket. In the logging case above, the after graph had no serialiser plateau at all, p95 went from 820 ms to 310 ms, and the SQL work we had done earlier was responsible for a small fraction of that.
Change one thing at a time. If you change three things and get 40% faster, you will not know which one to keep when the second change causes a bug.
Common mistakes
| Mistake | Why it hurts | Do this instead |
|---|---|---|
| Profiling with an empty dev database | Hot paths differ completely from production | Use production-like data volume |
| Reading x-axis as time | Flame graphs sort frames; order is meaningless | Read width only |
| Trusting absolute times under Xdebug | Instrumentation inflates small functions | Compare proportions; confirm with a sampling profiler |
| Optimizing a 3% bar | Effort with no visible gain | Start with the widest self-time bar |
| No baseline number | Cannot prove improvement or catch regressions | Record metric and scenario before changing code |
| Leaving profilers enabled in production | Overhead and exposed endpoints | Gate by trigger, IP and environment |
Key takeaways
- Write down the metric, baseline and scenario before you profile.
- Use sampling profilers (SPX,
--cpu-prof, py-spy) first; use instrumenting ones for detail. - In a flame graph, width is everything; left-to-right order means nothing.
- Fix the widest self-time bar, then re-profile, because the picture changes after each fix.
- Prove the win with the same measurement you used for the baseline.
References
- Brendan Gregg: Flame Graphs — https://www.brendangregg.com/flamegraphs.html
- SPX profiler (php-spx) — https://github.com/NoiseByNorthwest/php-spx
- Xdebug documentation: Profiling — https://xdebug.org/docs/profiler
- Node.js documentation: command-line options,
--cpu-prof— https://nodejs.org/api/cli.html - py-spy — https://github.com/benfred/py-spy
- speedscope — https://www.speedscope.app/
Comments
0No comments yet. Be the first to comment!
Sign In to post a comment.