Apache request latency: p50/p95/p99 from the access log %D field

“Apache is slow” is one of the least actionable statements in operations. The follow-up questions are always: slow for whom, on which URLs, and how slow at the tail? Averages cannot answer any of those. A server where every request takes 200ms and a server where half the requests take 5ms and half take 400ms have the same mean latency and completely different operational problems.

Apache gives you one high-resolution per-request number: the %D field in the access log, the request duration in microseconds. Logged on every completed request, it is the raw material for p50, p95, and p99 percentiles. This article covers what %D actually measures, how to compute percentiles from the log, how to read the resulting distribution, and the traps that make latency data lie to you.

Two warnings up front. First, mod_status exposes a DurationPerReq value that looks like the answer to this problem. It is not: it is a lifetime average since server start, so it smooths out every spike and is useless for real-time diagnosis. Second, log-based latency only records completed requests. A request stuck forever in a worker never produces a log line, which is why latency analysis always pairs with the scoreboard, covered below.

What %D actually measures

%D records the time taken to serve the request in microseconds: from the request timestamp captured while Apache reads the request line to the logger’s end timestamp, normally written after response processing. Treat it operationally as completion-to-last-byte latency, but do not use it as a byte-level socket-write clock. It is time-to-last-byte, not time-to-first-byte, and not “server processing time.”

That span contains distinct phases, and they matter when you interpret a number:

flowchart LR
  A[Apache reads request] --> B[Modules and handler run]
  B --> C[Backend wait - proxied only]
  C --> D[First response byte sent]
  D --> E[Response/logging completion]
  A -. "%D spans this entire range" .-> E

The consequences:

• Client transfer time is included. A 100MB download to a client on a 1Mbps link shows %D of roughly 800 seconds. Apache served that response instantly; the client read it slowly. This “client-induced latency” is the single most common source of misleading %D data.
• Backend time is included for proxied requests. When Apache reverse-proxies, %D is backend time plus Apache overhead plus client transfer. You cannot tell “Apache is slow” from “the backend is slow” from %D alone. See Apache backend response time: telling ‘Apache is slow’ from ’the backend is slow’.
• Log lines appear out of order for slow requests. Apache writes the access log entry when the response completes, so a 10-second request lands in the log after dozens of faster requests that started later. When you tail the log during an incident, the most recent lines are not necessarily the most recently started requests.

A few format notes worth knowing:

• %T records the same duration rounded to whole seconds. When most requests complete in under 100ms, %T rounds them all to zero. It is useless for latency monitoring, and using it is a common configuration mistake.
• %{ms}T records the duration in milliseconds, and %{us}T is equivalent to %D. The %{UNIT}T form was added in Apache 2.4.13; %D itself has been stable since Apache 2.0.
• If you need time-to-first-byte instead of time-to-last-byte, Apache 2.4.13+ can log %^FB from mod_logio, but only with LogIOTrackTTFB ON (it defaults to off). Without it, client-side measurement with curl -w "%{time_starttransfer}" is the practical way to compare TTFB against total time.

Why averages mislead and percentiles work

The distribution matters more than any single statistic:

• p50 is the typical experience. Half your requests are faster than this. If p50 doubles, something systemic changed.
• p95 and p99 are the tail: what your unluckiest users experience. Tail latency is where saturation, backend slowness, and resource contention show up first.
• The gap between p50 and p99 is consistency. A widening gap with a stable p50 means most requests are fine but something intermittently holds a minority of them: a slow backend member, garbage collection on the backend, lock contention, a noisy neighbor.

Averages hide all of this. A p99 of 8 seconds and a p99 of 80ms can produce the same mean if the traffic mix is right. Alerting on mean latency is how teams end up discovering tail problems from user complaints instead of from their monitoring.

Baseline expectations: static files served locally should have p99 under 10ms on healthy hardware. Proxied requests depend entirely on the backend, so there is no universal number; baseline per URL pattern and alert on deviation. At similar traffic levels, p50 should stay within about 20% of its baseline; a sustained 2x p50 is a ticket-worthy event.

One more boundary: any request taking more than 30 seconds is not “slow,” it is stuck. At that point latency analysis is the wrong tool. Look at the scoreboard worker states (a pile-up of W states usually means workers waiting on a backend) rather than at percentiles. See Apache BusyWorkers and IdleWorkers: reading worker utilization from mod_status.

Logging the field

If your LogFormat does not already include %D, add it. Appending it as the last field keeps the awk extraction simple:

# Duration in microseconds as the last field
LogFormat "%h %l %u %t \"%r\" %>s %b %D" combined_d
CustomLog /var/log/apache2/access.log combined_d

On RHEL-family systems the log path is typically /var/log/httpd/access_log instead of /var/log/apache2/access.log. Apply with apachectl configtest followed by a graceful reload (apachectl graceful), and confirm the new field appears in fresh log lines before trusting any numbers. If you run many virtual hosts with separate CustomLog directives, each one needs the field, or your per-vhost percentiles will have gaps.

If your format differs from the example, adjust the field position in the commands below. The examples assume %D is the final field ($NF in awk).

Computing p50, p95, p99 from the access log

The standard pipeline: take a recent window of requests, extract the %D field, sort numerically, and pick values at the percentile positions.

# p50/p95/p99/max over the last 1000 completed requests (%D as last field)
tail -1000 /var/log/apache2/access.log | awk '{print $NF}' | sort -n | awk '
  {a[NR]=$1} END {
    print "p50:", a[int(NR*0.5)], "us";
    print "p95:", a[int(NR*0.95)], "us";
    print "p99:", a[int(NR*0.99)], "us";
    print "max:", a[NR], "us"
  }'

Microseconds are awkward to read at scale; divide by 1000 for milliseconds or just remember that 1,000,000us is one second. A p99 of 250000 means your unluckiest 1% of requests took a quarter second.

Percentiles over the whole access log mix static assets, health checks, and application endpoints into one meaningless number. Baseline per URL pattern instead:

# p95 for one endpoint family only
grep ' /api/checkout' /var/log/apache2/access.log | tail -5000 | \
  awk '{print $NF}' | sort -n | \
  awk 'BEGIN{c=0}{a[c]=$1;c++}END{print "p95:", a[int(c*0.95)]" us"}'

Practical notes:

• Window size matters. With 1000 requests, p99 is roughly the 10th-slowest request: one outlier moves it. Use larger windows (5000-10000 lines) for stable tail numbers, smaller windows when you want recency during an incident.
• Exclude noise. Load balancer health checks inflate request counts and typically have near-zero duration, dragging p50 down. Filter them out by URL or user agent when baselining.
• The window is completion-ordered, not start-ordered. A tail -1000 window during a slow-backend event under-represents the stuck requests, because they have not completed yet and may never. If the access log goes quiet while traffic continues, that silence is itself the signal.

Reading the distribution

Two cross-checks make latency data trustworthy. First, compare with the scoreboard: high %D plus many W states points at backends or I/O; high %D with mostly idle workers points at something per-request (rewrites, mod_security, DNS lookups). Second, compare with the 5xx rate: slow and failing often travel together, and 504s specifically mark backend timeouts. See Apache 5xx error rate: 500 vs 502 vs 503 vs 504 and what each one means.

Known traps when interpreting %D

These are the failure modes of the measurement itself:

• Alerting on raw %D without filtering. Slow clients downloading large responses inflate the tail massively. Filter by response size or URL family before alerting, or your p99 alert fires on one user on hotel Wi-Fi pulling a big file.
• Using %T. Whole-second rounding destroys sub-second resolution. If your log format has %T, switch it to %D or %{ms}T.
• Trusting DurationPerReq. The mod_status value is an average since server start. On a server up for 30 days, an ongoing 10x latency regression barely moves it.
• Treating the log as complete. Timed-out and aborted requests never appear. During a worker-exhaustion event, the access log can look calm precisely because nothing is completing. Pair log analysis with BusyWorkers/IdleWorkers and listen backlog depth.
• One global baseline. Static files, API endpoints, and proxied app routes have different healthy latencies by orders of magnitude. Per-URL-pattern baselines or the percentiles are noise.
• Assuming %D isolates Apache. For proxied traffic it includes backend time; it never isolates the layers. When %D is high on proxied routes, the next step is always measuring the backend directly.

Signals to watch in production

How Netdata helps

• Netdata’s web log collector can parse the Apache access log continuously, turning %D values into live latency charts instead of awk pipelines you run after users complain. Configure it to group by URL pattern or the percentiles will have the same mixed-traffic problem as a whole-log awk run.
• Latency sits next to mod_status worker utilization and scoreboard states on the same dashboard, which is the correlation that separates “backend slow” (high p99 plus W pile-up) from “Apache saturated” (high p99 plus BusyWorkers near max) in one glance.
• Per-second request-rate and 5xx charts alongside latency make the “log goes quiet during worker exhaustion” failure visible instead of silent.
• ML-based anomaly detection on the latency series flags deviation from learned baselines, which is more useful than static thresholds when healthy latency differs by orders of magnitude across endpoints.
• Historical retention lets you compare p99 before and after a deploy or config change, which is the fastest way to confirm or rule out a regression.

Netdata’s Apache HTTP Server monitoring with Netdata brings these signals together with per-second metrics and ML anomaly detection.

Related guides

• How Apache HTTPD actually works in production: a mental model for operators
• Apache backend response time: telling ‘Apache is slow’ from ’the backend is slow’
• Apache BusyWorkers and IdleWorkers: reading worker utilization from mod_status
• Apache 504 Gateway Timeout: slow backends, ProxyTimeout, and worker pile-up
• Apache 503 Service Unavailable: worker exhaustion versus proxy pool exhaustion
• Apache 5xx error rate: 500 vs 502 vs 503 vs 504 and what each one means
• Apache error log monitoring: severity levels, AH codes, and what to alert on