A proxy debugging playbook

Most proxy incidents are diagnosed badly because the engineer starts by changing configuration. The method that works is the opposite: establish the topology, bisect it to find the innermost hop that still exhibits the fault, correlate a single request across every hop with an identifier, and only then read the configuration of the one component you have implicated. This page is that procedure in order, with the log formats and commands that make each step mechanical rather than intuitive.

The ordering matters because each step shrinks the search space. Topology turns "the site is broken" into a list of five components. Bisection turns five into one. Correlation turns one into one request. Everything after that is reading documentation for a single directive.

1. Establish the topology#

Ask for the architecture diagram, then assume it is wrong. Diagrams omit the transparent proxy the network team added, the WAF that runs as a sidecar, the service mesh that intercepts every outbound connection, and the CDN that someone enabled for the marketing site and left on. Discover the chain from the wire instead.

Response header fingerprints are the fastest signal. One verbose request usually names most of the chain:

curl -sSv -o /dev/null https://app.example.com/healthz 2>&1 | grep -E '^< '

X-Forwarded-For counts hops on the request side. Echo it back from a debug endpoint (or read it in the application log): a list of three addresses means at least three intermediaries appended to it. Combine with the X-Forwarded-For header and the client IP resolver to work out which entries you can trust.

The TLS certificate issuer tells you where TLS terminates. If openssl s_client -connect app.example.com:443 -servername app.example.com returns a certificate issued by your corporate CA rather than a public one, an intercepting proxy is in the path and everything you assumed about end-to-end TLS is wrong. See TLS interception and corporate root CAs.

Timing and TTL fill in the rest. curl -w breaks the request into phases, and a large gap between time_connect and time_appconnect on a supposedly local upstream suggests an extra network traversal:

curl -sS -o /dev/null -w \
'dns=%{time_namelookup} tcp=%{time_connect} tls=%{time_appconnect} ttfb=%{time_starttransfer} total=%{time_total} connects=%{num_connects}\n' \
https://app.example.com/healthz

tcptraceroute -p 443 app.example.com and the TTL of returned ICMP messages give you the L3 path, which is worth having when the L7 path looks shorter than the latency implies.

Write the result down as an ordered list with an address and a port per hop. That list is the object you are debugging for the rest of the incident.

2. Bisect the chain#

This is the technique that resolves most incidents, and it is underused because it requires shell access to intermediate hosts rather than a dashboard.

For each hop, from the host immediately in front of it, send the same request directly to that hop and observe whether the fault reproduces. The innermost hop that still shows the fault either is the faulty component or is being told to do the wrong thing by the hop in front of it.

The problem is that hitting a specific hop usually changes the Host header, the SNI and the port, which changes the routing and invalidates the test. curl solves this precisely:

# Hit the edge (normal path)
curl -sS -o /dev/null -w '%{http_code}\n' https://app.example.com/api/orders

# Hit the second-tier nginx directly, keeping Host and SNI intact
curl -sS -o /dev/null -w '%{http_code}\n' \
  --resolve app.example.com:443:10.0.2.20 https://app.example.com/api/orders

# Hit the origin on a different port, still with the right Host and SNI
curl -sS -o /dev/null -w '%{http_code}\n' \
  --connect-to app.example.com:443:10.0.1.10:8443 https://app.example.com/api/orders

# Hit the application without TLS at all, from the proxy host
curl -sS -o /dev/null -w '%{http_code}\n' \
  -H 'Host: app.example.com' http://10.0.1.10:8080/api/orders

--resolve overrides DNS for a host and port pair while leaving Host and SNI unchanged. --connect-to (curl 7.49.0 and later) additionally lets you redirect to a different port, which is what you need when the internal listener is not on 443. Both are far better than -H 'Host: ...' against an IP, because that form sends the IP as SNI and a TLS-terminating hop will reject it or serve the wrong certificate.

Record the outcome per hop in a table. A result like this localises the fault immediately:

The fault lives between the ALB and nginx, which in practice means the ALB's idle timeout, its health checks, or keep-alive mismatch, not the application. That is a completely different investigation from the one the 502 initially suggested. 502 vs 503 vs 504 enumerates the candidates for that gap, and keep-alive and upstream connection pooling covers the specific race that produces intermittent 502s between a load balancer and an upstream.

3. Correlate with a request ID#

Once you know the hop, you need one request's story across all of them. Generate an identifier at the outermost hop you control, propagate it inward, and log it everywhere. Without this, correlating by timestamp and URI is guesswork under load.

nginx has $request_id (16 random bytes as hex, available since nginx 1.11.0). Accept an incoming one if present, otherwise generate:

map $http_x_request_id $req_id {
    default $http_x_request_id;
    ""      $request_id;
}

server {
    location / {
        proxy_set_header X-Request-ID $req_id;
        add_header       X-Request-ID $req_id always;
        proxy_pass http://app_backend;
    }
}

The always on add_header matters: without it the header is omitted on error responses, which are exactly the ones you want to correlate.

HAProxy can generate a UUID (the uuid sample fetch was added in HAProxy 2.1) and capture it for the log:

frontend fe_main
    http-request set-header X-Request-ID %[uuid()] unless { req.hdr(X-Request-ID) -m found }
    http-request capture req.hdr(X-Request-ID) len 40
    log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %tsc %ac/%fc/%bc/%sc/%rc %{+Q}r rid=%hr"

Envoy generates x-request-id in the HTTP connection manager by default (generate_request_id defaults to true). It does not keep an inbound value on an external request unless you set preserve_external_request_id, which defaults to false, so an edge Envoy will replace an identifier your CDN already assigned. Add %REQ(X-REQUEST-ID)% to the access log format and set x-envoy-force-trace when you want the corresponding trace.

Then log the same field in the application. The payoff is a single grep across four log sources that produces one line per hop with timing at each, which turns a debate about whose component is slow into an arithmetic problem.

4. Read the logs in the right order#

Default log formats are close to useless for proxy debugging because they record what the client saw and nothing about the upstream. This is the nginx format worth standardising on:

log_format proxy escape=json
  '$remote_addr $host "$request" $status $body_bytes_sent $request_length '
  'rid=$req_id xff="$http_x_forwarded_for" proto=$server_protocol '
  'ups=$upstream_addr ups_status=$upstream_status '
  'ups_ct=$upstream_connect_time ups_ht=$upstream_header_time ups_rt=$upstream_response_time '
  'rt=$request_time cache=$upstream_cache_status ua="$http_user_agent"';

access_log /var/log/nginx/access.log proxy;

Every field earns its place:

• $upstream_addr is a list when nginx retried. 10.0.1.10:8080, 10.0.1.11:8080 means the first upstream failed and the second served the request, which is the difference between a healthy failover and a broken backend.
• $upstream_status is correspondingly a list. 502, 200 proves the client got a 200 despite an upstream failure, and hides an incident you would otherwise never see.
• $upstream_connect_time near your proxy_connect_timeout means a TCP-level problem (backlog, SYN drops, security group), not a slow application.
• $upstream_header_time vs $upstream_response_time separates time to first byte from time to last byte. A large gap means the response body is slow, which points at streaming, a large payload, or compression.
• $request_time vs $upstream_response_time is the single most informative comparison in the line.

$request_time is measured from the first byte read from the client to the last byte written to the client. $upstream_response_time covers only the upstream exchange. So:

The "slow client" case is the one that saves the most time. Mobile clients on poor networks, large downloads and clients that stop reading all inflate $request_time while the application is perfectly healthy. Alerting on $request_time alone generates pages that no application change can fix. See timeout budgets across a proxy chain for how these values should relate to each other, and check a chain with the timeout ladder checker.

HAProxy timers and termination flags#

HAProxy's log line encodes the whole request lifecycle in five numbers and two letters. In HTTP mode the five control points are %TR/%Tw/%Tc/%Tr/%Ta. The older Tq/Tw/Tc/Tr/Tt form is close but not equivalent: Tq is Th + Ti + TR and Tt is the total stream duration rather than the active time, so the manual recommends TR and Ta for new log formats.

-1 in TR, Tw, Tc or Tr means that phase never completed; Ta and Tt are never negative. Tw of -1 has its own meaning, that the request was killed before it reached the queue. The two-character termination state is then read as "what ended it" plus "where it was":

A 502 with SH and a 504 with sH are one character apart and have opposite fixes: SH means fix the upstream, sH means raise timeout server or make the upstream faster. A response HAProxy received but refused to pass on is PH rather than SH. HAProxy configuration has the surrounding directives.

Envoy response flags#

Envoy's %RESPONSE_FLAGS% is the equivalent, and %RESPONSE_CODE_DETAILS% is the field most people never enable and always need:

access_log:
- name: envoy.access_loggers.file
  typed_config:
    "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
    path: /dev/stdout
    log_format:
      text_format_source:
        inline_string: "[%START_TIME%] \"%REQ(:METHOD)% %REQ(X-ENVOY-ORIGINAL-PATH?:PATH)% %PROTOCOL%\" %RESPONSE_CODE% %RESPONSE_FLAGS% %RESPONSE_CODE_DETAILS% %DURATION% %REQUEST_DURATION% %RESPONSE_DURATION% %UPSTREAM_HOST% %UPSTREAM_CLUSTER% rid=%REQ(X-REQUEST-ID)%\n"

UF is upstream connection failure, UT upstream request timeout, UC upstream connection termination, UO upstream overflow (a circuit breaker tripped), UH no healthy upstream, NR no route configured, UPE upstream protocol error, DC downstream connection termination, RL rate limited, SI stream idle timeout. %DURATION% is the whole request from start time to the last byte out; %RESPONSE_DURATION% is from the same start time to the first byte read from the upstream, so the pair plays the same role as nginx's $request_time and $upstream_header_time. %REQUEST_DURATION% covers start time to the last byte received from the downstream. See Envoy listeners, routes and clusters.

5. Reproduce deterministically#

An intermittent fault is only tractable once you can measure its rate. Fix every variable you can, then loop:

for i in $(seq 1 200); do
  curl -sS -o /dev/null --http1.1 \
    -w '%{http_code} %{time_total} %{num_connects}\n' \
    https://app.example.com/api/orders
done | tee /tmp/run.txt | awk '{print $1}' | sort | uniq -c

The variables worth pinning explicitly, because each of them has independently caused "reproduces for me but not for you":

• HTTP version (--http1.1 vs --http2): upgrade and header handling differ per hop.
• Keep-alive (-H 'Connection: close' vs reuse): connection-reuse races are the classic intermittent 502.
• Source address, when the proxy has per-source routing, rate limits or sticky sessions.
• Cookies, because sticky sessions may pin you to the one broken backend.
• Header size, because a limit can be crossed by one user's token; see header and body size limits at the proxy.

%{num_connects} in that loop is worth watching: a value of 1 on every iteration means each request opened a new connection, so a keep-alive assumption somewhere is wrong.

Then correlate the failures. Join the failing request IDs against the proxy log and check whether the failures cluster on one value of $upstream_addr. If they do, it is one backend instance, and the fix is to remove it, not to change the proxy. That single check resolves a large fraction of "intermittent 502" reports.

6. Packet capture, only when necessary#

Reach for tcpdump when the logs contradict each other or when nothing is logged at all: connection resets, TLS handshake failures, and "the request never arrived" claims.

# Just the leg between this proxy and one upstream
tcpdump -i any -nn -s0 'host 10.0.1.10 and tcp port 8080' -w /tmp/upstream.pcap

# TCP resets anywhere, useful when a hop is closing connections
tcpdump -i any -nn 'tcp[tcpflags] & tcp-rst != 0'

# Client side, first packets of the handshake only
tcpdump -i any -nn 'tcp port 443 and (tcp[tcpflags] & (tcp-syn|tcp-fin|tcp-rst) != 0)'

With TLS you can still see plenty: the SNI in the ClientHello (unencrypted unless Encrypted Client Hello is in use), the negotiated version and cipher, the server certificate on TLS 1.2 (encrypted on TLS 1.3), record sizes, timing, and every TCP-level event including resets, retransmissions and zero-window stalls. You cannot see methods, URIs, headers or status codes. That is usually enough, because the questions packet capture answers best (who closed the connection, and when) are TCP questions.

When you truly need the plaintext, capture on the internal leg where the proxy talks to the upstream, which is frequently HTTP or TLS you control. Failing that, set SSLKEYLOGFILE for a curl or browser run and point Wireshark's TLS pre-master secret log at the file. Do not disable TLS in production to make debugging easier.

Symptom to first check#

The "works with curl, fails in the browser" row is the most misdiagnosed. curl sends about eight headers; a browser sends cookies, several Sec- headers, a long User-Agent and a Referer, and it may use HTTP/2 where curl used HTTP/1.1. Reproduce the browser's request properly before concluding the proxy treats clients differently: copy it out of the network panel as a curl command, then remove headers one at a time until it starts working. The header you removed is the answer.

Frequently asked questions#

What is the difference between request_time and upstream_response_time in nginx?#

$request_time measures the whole transaction from the first byte read from the client to the last byte written to the client; $upstream_response_time measures only the exchange with the upstream. When $request_time is much larger than $upstream_response_time, the client or the client's network is slow, not the application. Log both, because either one alone is ambiguous.

How do I find out how many proxies are in front of my application?#

Send one verbose request and read the response headers for Via, Age, X-Cache, CF-Ray, X-Amz-Cf-Id, x-envoy-upstream-service-time and Server, then count the entries in X-Forwarded-For as the application sees it. Check the TLS certificate issuer too: an unexpected issuer means a TLS-terminating hop you did not know about.

How do I test one hop of a proxy chain directly?#

Use curl --resolve host:443:<hop-ip> to override DNS while keeping the Host header and TLS SNI correct, or curl --connect-to host:443:<hop-ip>:<hop-port> when the internal listener is on a different port. Avoid curl -H 'Host: ...' https://<ip>/, because that sends the IP address as SNI and a terminating proxy will serve the wrong certificate or refuse the connection.

What does the HAProxy termination flag sH mean?#

sH means HAProxy hit timeout server while waiting for the server to send its response headers, and it returns 504 Gateway Timeout. The lower-case first character indicates a timeout; the upper-case SH instead means the server aborted before sending its full response headers, which produces a 502. A response that arrived but that HAProxy judged invalid is logged as PH, not SH.

Should I add X-Request-ID at the edge or let each proxy generate one?#

Generate it at the outermost hop you control and have every inner hop reuse the value it receives, otherwise you get several unrelated identifiers for one request and cannot join the logs. Inner hops should only generate an ID when the header is absent, and only the outermost hop should accept the header from an untrusted client.

Why does the request work from curl on the server but fail from the internet?#

Because the local test skips every hop in front of that server. Repeat the test from outside, then bisect inwards until the fault disappears; the hop where the behaviour changes owns the problem. This is also the standard way to distinguish an application fault from a proxy, CDN or WAF fault.

When is tcpdump worth the effort?#

When the logs on both sides disagree, when connections are reset with nothing logged, or when a TLS handshake fails before any HTTP exists to log. For everything else, structured proxy logs with upstream timings answer the question faster, and packet capture on a busy production host is expensive and awkward to filter.

How do I debug an intermittent failure that I cannot reproduce?#

Turn it into a rate. Loop a fixed request a few hundred times with pinned HTTP version and connection behaviour, build a status histogram, and then check whether the failures correlate with a single $upstream_addr, a single edge node, or a specific connection age. A fault you can measure at 2% is far easier to attribute than one you have only seen twice.