HAProxy HTTP log: timers and termination states

The HTTP log format

option httplog in a frontend turns on the HTTP format. The manual defines it as this exact log-format string:

# strict equivalent of "option httplog"
log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %CC \
            %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"

A line as it lands in a file through syslog:

Oct 18 10:02:02 lb1 haproxy[2201]: 198.51.100.7:40110 [18/Oct/2026:10:01:57.020] fe_http be_api/api-3 0/0/0/120/5032 200 65536 - - SD-- 315/301/44/15/0 0/0 "GET /api/export HTTP/1.1"

Reading the example: the server answered headers after 120 ms (Tr), then the connection to the server died with an error while the body was flowing (SD). The client got a 200 with 64 KiB of a response that was meant to be larger, 5032 ms after the request arrived. The status says success; the termination state says the download broke.

When the awk positions shift

The positions above assume the classic syslog header (Mmm dd hh:mm:ss host). An RFC 5424 or ISO-8601 header has a different number of words in front, and so does a log forwarded with an extra hostname. Captured headers only move fields after the queue counters. When in doubt, find the timer field (five numbers separated by slashes) and count from there; the one-liner below that finds the timer field does exactly that. The board does not care: it finds the client address and the request date and reads from there, whatever the header.

The five timers: TR / Tw / Tc / Tr / Ta

All values are milliseconds. They follow one request through the proxy:

first byte of the request                         last byte of the response
|                                                                         |
|-- TR --|-- Tw --|-- Tc --|-------- Tr --------|---------- Td ----------|
 request   queue    TCP      server works until    response body goes
 headers   wait     connect  response headers      out to the client
|<------------------------------- Ta ------------------------------------>|

Before TR: Th (TCP accept + TLS / PROXY handshakes) and Ti (idle, keep-alive)
Tq = Th + Ti + TR      Tt = Th + Ti + Ta      Td = Ta - (TR + Tw + Tc + Tr)

Timer patterns that point at the cause

Th, Ti, Td, Tt, Tq, Tu

• Th: TCP accept plus TLS and PROXY protocol handshakes. Reported only on the first request of a connection; later requests show 0.
• Ti: idle time before the request — time a pre-connected or keep-alive connection sat waiting. -1 if nothing was received.
• Td: transfer time of the response body, after the headers. Not in the default format; compute it as Ta − (TR + Tw + Tc + Tr), leaving out timers that are -1.
• Tt: whole stream duration, accept to close. For HTTP, Tt = Th + Ti + Ta.
• Tq: Th + Ti + TR. Older HAProxy versions logged Tq/Tw/Tc/Tr/Tt in the same position. Because Tq and Tt include handshake and idle time, they look much larger on keep-alive connections; the manual recommends TR over Tq.
• Tu: estimated time seen by the user — the stream duration without the idle time Ti.

Termination state: the four letters

Field 11 is two characters in TCP logs and four in HTTP logs. The first two say how the stream ended; the last two describe the persistence cookie, and are -- when cookies are not used. So the SD in a search for "SD--" is the part that matters, and cD-- is cD with no cookie involved.

First character: what ended the stream

Second character: the phase it was in

Third and fourth characters: the persistence cookie

Termination state reference: common combinations

The combinations the manual lists, what they mean in plain words, and where to look next. Uppercase is an abort or error, lowercase is a timeout.

Cookie combinations

Users complaining that they have to log in again? Look at II, DI, VI, EI and OI around that time: each one is a request that left its original server.

Connection counters, retries and queues

What the board shows for HAProxy

• Termination states: counts per state, each with its plain-language meaning, abnormal ones first.
• Request anatomy: TR, Tw, Tc, Tr and the transfer time as stacked bars, so you see whether time goes to the queue, the connect or the server.
• Topology from logs: frontend → backend → server drawn from fields 4 and 5, line width by traffic, red where errors come from.
• Retries and queue waiting, per backend and server.
• Look first: for example "HAProxy SD 61 times — backend be_api, server api-3".
• The usual cards too: status codes, top paths, top clients, latency, timeline.

Shell one-liners for HAProxy logs

Tested against a sample option httplog file with the classic syslog header. With another header, add or subtract the same offset from every field number, or use the one that finds the timer field.

• All termination states, most frequent first.

  awk '{print $15}' haproxy.log | sort | uniq -c | sort -rn

  Copy

• Only the first two characters (ignore cookie flags).

  awk '{print substr($15, 1, 2)}' haproxy.log | sort | uniq -c | sort -rn

  Copy

• Same, without trusting positions: finds the timer field and takes the fifth field after it.

  awk '{for (i = 1; i <= NF; i++) if ($i ~ /^-?[0-9]+\/-?[0-9]+\/-?[0-9]+\/-?[0-9]+\/\+?[0-9]+$/) {print $(i+5); next}}' haproxy.log | sort | uniq -c | sort -rn

  Copy

• Abnormal terminations per backend/server.

  awk 'substr($15, 1, 1) != "-" {print substr($15, 1, 2), $9}' haproxy.log | sort | uniq -c | sort -rn

  Copy

• Status codes per backend.

  awk '{split($9, b, "/"); print b[1], $11}' haproxy.log | sort | uniq -c | sort -rn

  Copy

• Requests where the server took over a second to send headers (Tr), with the state.

  awk '{split($10, t, "/"); if (t[4] > 1000) print t[4], $9, $15}' haproxy.log | sort -rn

  Copy

• Requests that waited in a queue (Tw > 0), with the queue positions.

  awk '{split($10, t, "/"); if (t[2] > 0) print t[2], $9, $17}' haproxy.log | sort -rn

  Copy

• Requests where the connection to the server never established (Tc = -1).

  awk '{split($10, t, "/"); if (t[3] == -1 && t[2] != -1) print $9, $11, $15}' haproxy.log | sort | uniq -c

  Copy

• Requests with retries; a "+" means redispatched.

  awk '{split($16, c, "/"); if (c[5] != "0") print c[5], $9, $15}' haproxy.log

  Copy

• Requests that never reached a server.

  grep -c '/<NOSRV> ' haproxy.log

  Copy

• p99 of Ta, total active time.

  awk '{split($10, t, "/"); sub(/^\+/, "", t[5]); print t[5]}' haproxy.log | sort -n | awk '{a[NR]=$1} END {i=int(NR*0.99); if (i<NR*0.99) i++; print a[i] " ms"}'

  Copy

• Highest process-wide connection count seen.

  awk '{split($16, c, "/"); if (c[1] > m) m = c[1]} END {print "peak actconn", m}' haproxy.log

  Copy

• Longest body transfer times (Td = Ta − TR − Tw − Tc − Tr).

  awk '{split($10, t, "/"); if (t[1] >= 0 && t[2] >= 0 && t[3] >= 0 && t[4] >= 0) print t[5]-(t[1]+t[2]+t[3]+t[4]), $9}' haproxy.log | sort -rn | head -3

  Copy