Open your Apache access log and look at the request duration field. If every line shows 0, your monitoring pipeline is probably fine. Your LogFormat is the problem. The %T directive logs time to serve the request in whole seconds, so any request that completes in under one second logs as 0. On a fleet where most requests finish in well under 100ms, %T collapses the entire latency distribution into a single useless value.

This usually goes unnoticed until someone builds a latency dashboard on top of the access log and gets a flat line of zeros. The fix is a one-token change: log %D (microseconds) or %{ms}T (milliseconds) instead. This article covers what each directive records, gives you a corrected combined-log LogFormat, and shows where the duration field lands so percentile extraction works.

What each directive actually logs

All of these come from mod_log_config. The differences are unit and availability:

DirectiveUnit loggedA 50ms request logs asAvailability
%Tseconds, integer0all 2.2.x and 2.4.x
%Dmicroseconds, integer50000all 2.2.x and 2.4.x
%{ms}Tmilliseconds, integer502.4.13 and later
%{us}Tmicroseconds, integer500002.4.13 and later

A few things worth knowing:

  • The values are integers. %D does not give you decimal seconds; it gives you a raw microsecond count. 50000 means 50ms, not 50000 seconds.
  • %{s}T is the same as %T, and %{us}T is the same as %D. The unit-form syntax exists so you can pick milliseconds, which has no single-letter equivalent.
  • %{UNIT}T in any form requires Apache 2.4.13 or later. Before that, %D is the only sub-second option.
  • Do not confuse %T (request duration, seconds) with %t (the timestamp the request was received). They are unrelated fields that differ only by case.

Why %T breaks latency monitoring

The failure is silent. Nothing errors. The log looks well-formed, the field is populated, and every downstream parser works. The data is just rounded into meaninglessness:

  • Percentiles flatline. p50, p95, and p99 of a column of zeros are all zero. A latency dashboard renders a flat line that looks like excellent performance.
  • Deviation alerts never fire. An alert like “p95 greater than 2x baseline” compares against a baseline of 0 and sees 0 forever.
  • Real regressions are invisible. A shift from 40ms to 400ms typical latency is a 10x degradation that your users feel. Under %T, both log as 0. You only see a change once requests cross the one-second boundary, and even then 1.0s and 1.9s both log as 1.

By the time %T shows anything at all, the service is not “a bit slow”. It is in serious trouble, and you have lost every leading indicator that would have told you earlier.

What the duration field actually measures

%D and %{ms}T measure the time from when Apache receives the request to when it finishes sending the response. That span covers module processing, any backend wait for proxied requests, and the network transfer to the client:

flowchart LR
  A["Request received"] --> B["Module pipeline"]
  B --> C["Backend wait (proxy only)"]
  C --> D["Response transfer to client"]
  D --> E["Access log line written"]
  A -- "%D and %{ms}T span" --> D

The client transfer segment matters operationally. A slow client downloading a large response inflates the duration even when Apache served it instantly. The playbook example: a 100MB file to a 1Mbps client shows a duration of roughly 800 seconds. That is not Apache being slow. Keep this in mind when you build alerts on the field, and see the pitfalls section below.

Check your current format and version

Before changing anything, confirm which directive you are logging today and which Apache build you run:

# Find every active log format and log destination
grep -rE '^[[:space:]]*(LogFormat|CustomLog|TransferLog)' /etc/apache2/ /etc/httpd/ 2>/dev/null

# Check the Apache version (needs 2.4.13+ for %{ms}T)
apachectl -v 2>/dev/null || httpd -v

The grep matters more than it looks. The duration directive has to be in the LogFormat that each CustomLog actually references, on every vhost that matters. A LogFormat line that defines a nickname nobody uses changes nothing.

The corrected LogFormat

Start from the standard combined format and append the duration as the final field:

# Microseconds: works on every 2.2.x and 2.4.x build
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %D" combined

# Milliseconds: Apache 2.4.13 and later
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %{ms}T" combined

Two deliberate choices here:

  • Duration goes last. The referer and user-agent fields are quoted and contain spaces, so positional field extraction with awk breaks unless the duration is the final whitespace-separated token. Appending it last means $NF in awk always lands on the duration. If you add fields after it later, update your extraction.
  • Pick %D unless you know every host is 2.4.13+. %D works everywhere and microseconds never hurt; you can divide downstream. %{ms}T reads more naturally but fails on older builds.

Apply it with a config test first, then a graceful reload, and confirm the reload actually took:

# Validate before reloading
apachectl configtest

# Graceful reload (keeps serving, no dropped connections)
apachectl graceful

# Confirm the new config is actually running
grep "resuming normal operations" /var/log/apache2/error.log | tail -1

On RHEL/CentOS the error log is /var/log/httpd/error_log. That last check is not paranoia: if the config fails validation at reload time, Apache keeps running the old configuration. Your new LogFormat never takes effect and nothing tells you.

Verify the change

Generate a few requests and look at the last field:

for i in 1 2 3 4 5; do curl -s -o /dev/null http://localhost/; done
tail -5 /var/log/apache2/access.log

You should see a non-zero integer as the final token on each line. On Debian/Ubuntu the default path is /var/log/apache2/access.log; on RHEL/CentOS it is /var/log/httpd/access_log.

Then confirm percentile extraction works end to end:

# P50/P95/P99 from the last 1000 completed requests (duration in the last field, microseconds)
# The numeric filter skips any lines still in the old format from before the reload
tail -1000 /var/log/apache2/access.log | awk '$NF ~ /^[0-9]+$/ {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"
  }'

If you logged %{ms}T, the same pipeline works and the output unit is milliseconds instead.

Common pitfalls

  • %{ms}T on Apache older than 2.4.13. The unit-form syntax does not exist before 2.4.13, and enterprise distros lag: RHEL 7 ships Apache 2.4.6. On those builds, use %D.
  • HTTPS vhosts logging separately. On RHEL/CentOS, conf.d/ssl.conf ships its own TransferLog/CustomLog lines for ssl_access_log. Editing the LogFormat in httpd.conf does not reach it. Update the SSL config too, or your HTTPS traffic keeps logging without the duration field.
  • Client transfer time inflating the field. %D includes the time to send the response to the client. One slow client on a large download produces an 800-second entry that wrecks your p99. Filter by endpoint class or response size before alerting on the raw distribution.
  • Microseconds are integers, not decimal seconds. If downstream tooling expects seconds, divide by 1,000,000 in the parser. Do not try to make Apache emit decimal seconds; it will not.
  • Only completed requests are logged. A worker stuck on a hung backend writes nothing until the request finishes or times out. Log-based latency always lags a live stall, so pair it with scoreboard worker states from mod_status.
  • mod_status duration is a lifetime average. DurationPerReq in server-status averages every request since the last restart. On a long-running server it smooths out every spike. Use log percentiles for current latency and treat the mod_status figure as a rough sanity check only.

Signals to monitor

Once the field has real precision, these are the signals worth tracking:

SignalWhy it mattersWarning sign
p50 from %D or %{ms}TTypical user experienceDrift beyond ~20% of baseline at similar traffic
p95/p99Tail latency, where users actually sufferSustained 2x baseline
Slowest requestsDistinguishes “slow” from “stuck”Any request over 30s is almost certainly stuck, not slow
p95 alongside scoreboard W-state shareSeparates “Apache is slow” from “backend is slow”Many workers in W with rising p95 points at the backend or I/O, not Apache

The last row is the one that saves hours during an incident. In proxy deployments, a slow backend holds Apache workers while they wait, and the access log duration climbs for reasons that have nothing to do with Apache itself. See Apache backend response time: telling ‘Apache is slow’ from ’the backend is slow’ for that diagnosis.

How Netdata helps

  • Netdata’s Apache collector polls mod_status once per second: BusyWorkers, IdleWorkers, full scoreboard state distribution, and request rate, so a latency regression can be checked against worker saturation immediately instead of sampled by hand.
  • Its web log parsing turns the access log duration field into per-second response-time charts. Sub-second precision in that field is exactly what this fix provides; with %T those charts are as flat as any other zero-column dashboard.
  • Correlating log-derived p95 with the scoreboard W-state share and backend response time is what separates “Apache is slow” from “the backend is slow” during an incident.
  • Anomaly detection on request rate and worker utilization flags the regression window even when latency is still inside static alert thresholds.

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