After a release, a PHP product page is 800 ms slower in production; how do you find the slow path instead of guessing at it?
answer
- confirm, scope, then measure
- wall versus CPU split first
- hrtime spans per phase
- sample a fraction of production
- diff the old and new profile
basics
~20 sConfirm and scope the regression, split wall time from CPU time, narrow it with hrtime spans around each phase, then profile production traffic with a low-overhead sampling profiler on a small fraction of requests and compare against the previous release.
solid answer
~40 sFirst **confirm and scope**: which percentile moved, on which route, for all products or only some, starting exactly with the deploy. Then **split** wall from CPU time with per-request `hrtime(true)` and `getrusage()` deltas: if CPU barely changed, the new time is waiting on I/O. Next, **narrow** with `hrtime()` spans around the phases (queries, outbound HTTP, rendering), logged with the request id, to find the phase that grew. Then **profile**: a sampling profiler on a small fraction of production requests, or on requests carrying a trigger, shows the stack at real data volumes. Where you need exact call counts, reproduce with production-like data under an instrumenting profiler. **Diff** old against new: which function's inclusive time grew, and did a call count jump from 3 to 240? Fix, then verify with the same measurement.
go deeper
Know that slowness is measured, not guessed: time the request, then time its parts. Mention hrtime(true) for durations.
Describe the wall-versus-CPU split with getrusage() deltas and hrtime spans around queries, HTTP calls and rendering. Explain why production-sized data matters.
Lead the investigation in order: scope, split, spans, sampled production profiles, and a diff against the previous release with call counts. Explain why instrumentation stays out of full production traffic.
Turn the investigation into prevention: per-route latency budgets, spans and CPU time logged by default, and profile comparisons in the release process, so the next regression is caught before users notice.
## Principle: measure, narrow, then profile "The page got slower after the release" is a symptom. Guessing from the diff ("it must be the new serializer") wastes days when the release contained fifty changes. The method below narrows the search step by step, and each step is cheap before the next, more expensive one. ## Step 1: confirm and scope Before touching a profiler, answer: - **Which metric moved?** p50 and p95 tell different stories. If the median is unchanged but p95 grew by 800 ms, a subset of requests got slow, often a data-dependent path. - **Where?** One route, or all routes? If every page is slower, suspect something shared (bootstrap, configuration, a middleware, a cache that stopped hitting). If only the product page is slower, suspect code on that path. - **Which products?** Products with many reviews or variants often expose a loop whose cost grows with the data. - **When?** A change that starts precisely at the deploy and stays points at the release; one that fades after a few minutes points at a transient warm-up instead. ## Step 2: split wall time and CPU time Log per-request wall time from `hrtime(true)` deltas and CPU time from `getrusage()` deltas (user plus system, snapshot at start and end, since an FPM worker's counters span many requests). | Before | After | Reading | |---|---|---| | 200 ms wall / 120 ms CPU | 1,000 ms wall / 130 ms CPU | the new time is **waiting**: queries, HTTP calls, locks | | 200 ms wall / 120 ms CPU | 1,000 ms wall / 900 ms CPU | the new time is **PHP computing** | This single split decides whether you look at I/O or at code. ## Step 3: narrow with spans Wrap the main phases in `hrtime(true)` spans and log them with the route and request id: loading the product, loading reviews, calling the pricing API, rendering the template. Aggregated over a few thousand requests, one phase will stand out. This costs almost nothing and runs safely in production. ## Step 4: profile in production, carefully Spans tell you which phase; a profiler tells you which function inside it. 1. **Sampling in production.** Enable a sampling profiler on a small fraction of requests (for example one in a hundred), or only on requests that carry a trigger such as a header your team controls. Overhead stays bounded, and the profile reflects real data, real caches and real concurrency. 2. **Wall-clock mode** if Step 2 showed waiting, **CPU mode** if it showed computation. 3. **Instrumentation in reproduction.** When you need exact call counts, reproduce the slow request in staging with production-sized data and run an instrumenting profiler there. Never switch an instrumenting profiler on for all production traffic: its per-call overhead would slow every request and skew the results. ## Step 5: compare against the previous release A single profile shows where time goes; a **comparison** shows what changed. Profile the same route on the old and new release (or old and new data) and diff: - **inclusive time** per function: which subtree grew by roughly 800 ms? - **call counts**: did `PDOStatement::execute()` go from 3 calls to 240, or a remote client's call from 1 to 50? - **new frames**: functions that did not appear before at all. Typical findings behind a sudden 800 ms: a lazy-loaded relation accessed inside a loop, a cache lookup whose key now changes on every request, a new outbound call made synchronously, or a regular expression or sort applied to a much larger input. ## Step 6: fix and verify with the same measurement After the fix, check the same percentiles, the same wall/CPU split and the same spans that exposed the problem. A fix that looks right in a local benchmark but does not move production p95 has not fixed the regression. ## Traps - Profiling locally with ten products when production has thousands of reviews per product. - Reading an instrumented profile's absolute times as production latency. - Declaring victory from one fast request. - Blaming the most recently changed file without evidence. - Profiling right after a deploy, when first requests pay one-time warm-up costs that later requests do not.
- Why not simply enable an instrumenting profiler on every production request until the slow path shows up?Its per-call overhead would slow every request, possibly more than the regression itself, and it inflates call-heavy code, so the profile would misrepresent where production time goes. Sampling a fraction of requests, or triggering profiling on chosen requests, keeps overhead bounded and results representative. Use instrumentation in a reproduction environment when you need exact counts.
- The slowdown appears only for some products. How does that change the investigation?It points at a data-dependent path: code whose cost grows with the number of reviews, variants or images. Profile a slow product and a fast one and compare call counts. A function whose calls scale with the product's data, such as one query per review, is usually the cause, and it would not show up at all when testing with small fixtures.
- Profiling shows the new time inside curl_exec() calls to an internal pricing service. Is the investigation over?It has moved rather than finished. The PHP side now needs call counts and timing: is the release calling the service more often, sequentially instead of once, or with larger payloads? If the count is unchanged, the latency is the service's own and the investigation continues on that service's side. Either way, the evidence now names a specific call.
saying these in an interview costs you the question
- Starts by reading the release diff and guessing which change caused it.
- Turns on an instrumenting profiler for all production traffic.
- Reproduces the slowdown locally with tiny fixture data and finds nothing.
- Looks only at average latency and misses a slow subset of requests.
- Declares the regression fixed after one fast request in staging.