Apache %D includes client transfer time: the latency alert that cries wolf

Your p99 latency alert fired at 03:00. You pull the access log, sort by %D, and find requests with durations of 400, 600, even 800 seconds. The server looks fine: CPU normal, workers mostly idle, backend healthy. The “slow” requests are large file downloads to clients on slow connections. Apache served the response instantly; the client took thirteen minutes to read it.

%D does not measure how long Apache took to process the request. It measures the time from when Apache read the request to when the last byte of the response was handed to the OS network stack, and that second part is paced by how fast the client consumes data. TCP send buffers are finite. When the buffer fills, Apache blocks in write() until the client drains it. A 100MB download to a 1Mbps client shows %D of roughly 800 seconds even though server-side work took milliseconds.

Alert on raw %D with a flat threshold and large responses plus slow clients page you for problems that do not exist, while genuinely slow server-side requests hide in the noise. This article covers what %D actually measures, how to separate client-induced latency from processing latency, and how to rebuild the alert so it means something.

What this means

The %D directive in LogFormat records the time taken to serve the request, in microseconds. The clock starts when Apache reads the request from the OS and stops when the last byte of the response is written to the OS network stack. Everything in between counts:

• Reading the request body (slow uploads inflate it)
• Processing: handlers, modules, backend waits if proxying
• Writing the response, which blocks whenever the client is slower than the server

It excludes the TCP and TLS handshakes and any time the connection spent in the accept queue before a worker picked it up. So %D can look fine even when clients experience long connection setup times, and it can look terrible even when the server side was instant.

flowchart LR
  A[Client connects] --> B[TLS handshake]
  B --> C[Accept queue]
  C --> D[Apache reads request]
  D --> E[Processing / backend wait]
  E --> F[Response written to OS]
  F --> G[Client reads at its own pace]
  D -. "%D clock starts" .-> D
  F -. "%D clock stops" .-> F

The segment from “reads request” to “response written” is what %D covers. The hop from “written to OS” to “client has the bytes” is not Apache’s problem, but it directly stretches the measured interval because the write path blocks on the client.

Units matter: %D is microseconds. %T is the same interval in whole seconds, which rounds away anything sub-second and is useless for latency monitoring. %{ms}T (milliseconds) has been available since Apache 2.4.13 and is usually the right unit.

Common causes of inflated %D

The first three are client-induced. Only the last two are server-side. Your alert should fire on the last two and ignore the rest.

Quick checks

These are read-only. Adjust log paths and field positions for your LogFormat.

# P50/p95/p99 of %D over the last 1000 requests (assumes %D is the 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"
  }'

# Correlate duration with response size: high %D AND high bytes = transfer-bound
# Assumes %D is last field, bytes (%b) is field 10 in combined format. Adjust to yours.
tail -5000 /var/log/apache2/access.log | \
  awk '{dur=$NF; bytes=$10; if (dur > 5000000) print dur/1000000 "s", bytes/1048576 "MB", $7}' | \
  sort -rn | head -20

# What are workers doing right now? Many W with slow backend vs many R with slow uploads
curl -s http://localhost/server-status?auto | grep Scoreboard | \
  sed 's/Scoreboard: //' | fold -w1 | sort | uniq -c | sort -rn

# Client-side split of TTFB vs total time for a suspect endpoint
curl -s -o /dev/null -w "TTFB: %{time_starttransfer}s  Total: %{time_total}s\n" http://localhost/some-page

# Check which log directives are in use (are you even logging %D, %O, %{ms}T?)
grep -rE 'LogFormat|CustomLog' /etc/apache2/ /etc/httpd/ 2>/dev/null | grep -v '^#'

How to diagnose it

1. Confirm the alert is transfer noise, not processing time. Join the requests that breached the threshold against response size. If the high-%D requests are also the high-byte requests, you are looking at client transfer time, not server slowness. A back-of-envelope check: bytes divided by %D gives effective throughput to that client. If that number is in the kilobits-per-second range, the client link is the constraint.

2. Check TTFB against total time. For the suspect endpoint, measure %{time_starttransfer} versus %{time_total} with curl from localhost. If TTFB is fast and total time scales with response size, Apache is fine and the response is transfer-bound. If TTFB is high and total time roughly equals TTFB, the processing itself is slow.

3. Look at the scoreboard during the alert window. Many workers in W with a slow backend points to server-side or backend latency. Many workers in R points to slow request bodies or slow-read clients. A mostly idle scoreboard during a %D alert almost always means client-induced latency.

4. If proxying, separate backend time from client time. In proxy mode %D bundles backend wait, Apache processing, and client transfer into one number. You cannot tell “Apache is slow” from “the backend is slow” from %D alone. Test the backend directly, bypassing Apache, and compare. See Apache backend response time: telling ‘Apache is slow’ from ’the backend is slow’.

5. Check what %D never sees. %D excludes accept-queue wait and connection setup. If clients complain about slowness but %D is clean, check the listen backlog with ss -ltn and look for worker saturation.

Metrics and signals to monitor

Fixes

Fix the log format first

You cannot alert on what you do not log. At minimum, log duration, response size, and request size together so every latency sample can be classified:

# Requires mod_logio for %I and %O
LogFormat "%h %l %u %t \"%r\" %>s %O %I %D %{ms}T" timed
CustomLog /var/log/apache2/access.log timed

%O is bytes actually sent over the network, %I is bytes received, %D is microseconds, %{ms}T is milliseconds (Apache 2.4.13 and later; on older versions you only have %D and %T). With size and duration on the same line, downstream analysis can compute effective throughput per request and separate transfer-bound from processing-bound.

For a true server-side TTFB in the log itself, Apache 2.4.13+ offers %^FB via mod_logio, which logs the delay in microseconds between when the request is read and the first byte of the response headers is written. It requires LogIOTrackTTFB On, which defaults to Off. This is the cleanest way to get TTFB out of Apache without client-side measurement.

Tradeoff: changing LogFormat breaks any existing log parsers. Coordinate with whatever consumes the logs before deploying.

Fix the alert logic

A flat %D > 5s threshold is the actual bug. Replace it with logic that classifies before it alarms:

• Filter by response size. Only alert on high %D when the response is small (say, under 100KB). Large responses get a separate, looser threshold or no alert at all.
• Alert on TTFB, not total time. If you log %^FB, threshold that instead. TTFB is what your backend and Apache processing control.
• Use percentiles per endpoint class. Static downloads, API calls, and proxied requests have wildly different latency profiles. One global threshold fits none of them.
• Keep %T out of it. Whole-second rounding makes everything under one second invisible.

Fix the underlying condition, if there is one

If after filtering you still see server-side slowness: many W states with high TTFB means processing or backend time is the problem, and you are back in normal latency triage. Many R states means slow uploads or slow-read clients; confirm that mod_reqtimeout is loaded and configured for your upload endpoints—many distributions enable it, but the module is not universally loaded. If clients genuinely are slow and downloads are large, that is a content-delivery problem (compression, caching, CDN), not an Apache problem.

Prevention

• Baseline per endpoint, not globally. Latency expectations for a 200MB download and a JSON API call differ by orders of magnitude. Build baselines by URL class before setting any threshold.
• Always log size with duration. Any latency field without a corresponding byte count will eventually produce exactly this false positive.
• Prefer %{ms}T or %D over %T. Second-resolution latency data is not latency data.
• Alert on worker states and TTFB for server health; alert on filtered %D for user experience. These are two different questions and deserve two different alerts.
• Revisit thresholds after content changes. Shipping larger assets or enabling downloads changes the transfer-time distribution overnight.

How Netdata helps

Netdata’s Apache monitoring and log-based metrics line up well with this specific failure mode:

• Per-second BusyWorkers and IdleWorkers from mod_status let you confirm instantly whether a %D alert coincided with actual worker saturation or with idle, healthy workers.
• Scoreboard state distribution over time shows whether elevated latency windows correlate with W states (writing/backends) or R states (slow clients), which is the key classification step.
• Request rate and bytes-served rate from Total Accesses and Total kBytes let you compute average response size trends, so you can see when content changes shift the transfer-time baseline.
• Web log parsing exposes duration and status dimensions from the access log, so latency percentiles can be charted next to throughput and error rate in one view instead of awk one-liners during an incident.
• Correlating listen backlog depth and connection counts with latency alerts catches the inverse case: real slowness that %D cannot see because requests never reached a worker.

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

Related guides

• Apache 500 Internal Server Error: modules, handlers, and misconfiguration
• Apache 502 Bad Gateway: a backend that returned an invalid response
• Apache 503 Service Unavailable: worker exhaustion versus proxy pool exhaustion
• Apache 504 Gateway Timeout: slow backends, ProxyTimeout, and worker pile-up
• Apache 5xx error rate: 500 vs 502 vs 503 vs 504 and what each one means
• Apache AH00558: Could not reliably determine the server’s fully qualified domain name
• Apache backend response time: telling ‘Apache is slow’ from ’the backend is slow’
• Apache balancer member in error state: reading balancer-manager and failover
• Apache BusyWorkers and IdleWorkers: reading worker utilization from mod_status
• Apache CLOSE_WAIT and TIME_WAIT: connection leaks versus normal churn
• Apache error log monitoring: severity levels, AH codes, and what to alert on
• How Apache HTTPD actually works in production: a mental model for operators