Server or application bottleneck: how to measure it

Time to first byte at every hop

Theories about a slow site are easy to form and hard to settle. Three measurements settle them. Take time to first byte through the public edge, again directly against the origin with the edge bypassed, and again on the application host against localhost. The difference between two adjacent readings is that layer's cost.

# through the edge
curl -s -o /dev/null -w 'dns=%{time_namelookup} tls=%{time_appconnect} ttfb=%{time_starttransfer}\n' https://site.example/

# direct to the origin, edge bypassed
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' --resolve site.example:443:ORIGIN_IP https://site.example/

# on the host, nothing in front of the application
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' http://127.0.0.1/

Whatever remains on localhost is the application and the services it calls. The layer with the biggest gap is where the rest of the work goes.

Headroom while it hurts

Read the counters during the slow period, not after it.

vmstat 1 5        # r (run queue), wa (I/O wait), st (steal), id (idle)
iostat -x 1 5     # await and aqu-sz per device
free -m           # the available column, not used

A long run queue with low idle is a CPU-bound box. High I/O wait with high await on the device is storage. Steal is a neighbour on a shared hypervisor taking cycles the guest wanted. Idle CPU, memory available and devices with low await under a slow site mean the box is waiting on something the box does not own: an external call, a lock, a query that is slow for reasons other than hardware. Adding hardware at that point produces a more idle machine that is still slow.

There is a third category between the two, and it is common: the pool. PHP-FPM's status page shows a listen queue; a queue of waiting requests with idle CPU means every worker is occupied, usually blocked on the same slow call, and the site is slow because of a configuration ceiling rather than a resource ceiling. The same shape appears as a saturated database connection pool or a full HAProxy backend queue. The box is innocent and the code is not yet convicted; the pool size and the call it is waiting on are the next two readings.

Read the traffic before the code

The access log says what kind of problem this is. Find the per-vhost log first; the default log can carry a small fraction of the real traffic and a count over the wrong file gives a confident wrong answer.

tail -n 100000 access.log | awk -F'"' '{print $2}' | sort | uniq -c | sort -rn | head

A few URLs repeated thousands of times is the site calling itself, and the fix is a cache in front of those URLs. Requests marching in sitemap order are a crawler, and the fix is a rate limit. A broad, even rise across many URLs is demand, and the fix is capacity.

Collapse the slow log and the query log

A slow log is a pile of stack traces until it is keyed. Enable the PHP-FPM slow log with a threshold that catches the requests users complain about, then key each trace on the frame it was blocked in, the leaf, and count. The ranked list is short and the top is usually one external call or one query.

On the database side, rank by digest, not by plan. Inconsistent parameterisation splits one logical query into many plans that each look harmless; summed by digest the real owner of the database's time reassembles into one row.

-- MySQL and Percona: by statement digest
SELECT digest_text, count_star, sum_timer_wait
FROM performance_schema.events_statements_summary_by_digest
ORDER BY sum_timer_wait DESC
LIMIT 10;

-- SQL Server: by query hash
SELECT query_hash, COUNT(*) AS plans, SUM(total_worker_time) AS cpu
FROM sys.dm_exec_query_stats
GROUP BY query_hash
ORDER BY cpu DESC;

Before any index is written, verify the real row count and the indexes that already exist. An index on a table that does not need one is a slower write path.

Read the primary source, not a plausible story

Each row replaces a theory with a reading. The last one matters on an enforcing system: the audit log answers the question without changing the security posture to ask it.

Prove it, then verify with the same measurement

Correlation gives a suspect. A small, reversible perturbation convicts it: stop the suspect queries for a few seconds and watch whether load refills. If it refills at once, live traffic is the driver and the fix belongs at the edge, in front of the requests that should not reach the database at all. Until the cause is known, the system is read-only. When the fix is in, it is verified with the measurement that found the problem: if time to first byte per hop located it, time to first byte per hop confirms it is gone.

What we fix and what we hand back

We do not change your code. We name the line, show the measurement that points at it and keep the site up while you fix it.