DEV Community

Alex Georgiev
Alex Georgiev

Posted on AI-assisted

Traefik 3.8's tap middleware triples request latency even with an instant local receiver

Traefik 3.8.0-rc.1 shipped on 30 October with a middleware called tap. It copies every request and response passing through a router and posts each one, as a JSON record, to a Traefik service of your choosing. It is meant for audit logging or compliance trails without rewiring your application.

The documentation is upfront about the cost: "the time taken by the tap service adds to the latency of every request," because the record is sent inline rather than in the background. I wanted to know how much that actually costs, whether it is really strictly additive as worded, and what happens when the tap endpoint is slow, unreachable, or fed more than it can handle.

This is a release candidate, not a stable release, so none of this is final. But the behaviour is unlikely to change much before 3.8.0 ships, since it is documented as intentional.

The setup

I ran Traefik 3.8.0-rc.1 in Docker, routing to traefik/whoami (a trivial Go binary that echoes the request back, chosen so the backend itself adds almost no latency of its own) and a small Python http.server standing in for the tap receiver, all on one Docker bridge network so there was no real network hop to account for.

http:
  middlewares:
    tap-fast:
      tap:
        request:
          service: tapsvc
          path: /req
          timeout: 5s
        response:
          service: tapsvc
          path: /resp
          timeout: 5s
Enter fullscreen mode Exit fullscreen mode

Baseline latency, no tap, 100 sequential requests, three runs:

run mean p50 p95
1 0.88ms 0.87ms 1.05ms
2 1.09ms 1.08ms 1.48ms
3 0.94ms 0.85ms 1.01ms

With the tap middleware attached, pointed at the same receiver on the same host, answering instantly:

run mean p50 p95
1 2.49ms 2.37ms 3.34ms
2 2.68ms 2.58ms 3.34ms
3 2.67ms 2.58ms 3.17ms

That is roughly triple the baseline mean, and the gap holds steady across all three runs. This is the best case: receiver on the same Docker network, no payload, no slowdown of its own. There is no way to get a better number out of this middleware than the one above.

The documented claim holds, almost exactly

The quoted sentence from the docs is a specific, checkable claim: the tap service's own latency becomes part of the request's latency. I set the receiver to sleep before responding and reran the same benchmark.

receiver delay tapped request latency (mean)
0ms 2.6ms
10ms 23.3ms
50ms 104.9ms

A 10ms receiver delay added about 20ms, not 10. A 50ms delay added about 100ms, not 50. That is because tap records the request and the response separately, each a synchronous call, so a slow receiver gets charged twice per client request. The documentation doesn't spell out the factor of two; I only found it by varying the delay and checking the arithmetic.

What it refuses: an unreachable tap service becomes an outage

I killed the receiver (dropped the TCP connection instead of answering) and hit a route configured with rejectOnRecordError: true:

HTTP/1.1 500 Internal Server Error
Content-Type: text/plain; charset=utf-8

Internal Server Error
Enter fullscreen mode Exit fullscreen mode

Every real request behind that router now fails, with no detail beyond "Internal Server Error", until the audit endpoint comes back. That is the documented behaviour, and it is a serious thing to turn on for a production router without a highly available tap endpoint behind it.

With rejectOnRecordError: false against the same dead receiver, the real request still returned 200 normally. Traefik logged the failure instead of surfacing it to the client:

ERR Unable to send the request record  error="tap service returned 502" middlewareName=tap-noreject@file middlewareType=Tap
ERR Unable to send the response record error="tap service returned 502" middlewareName=tap-noreject@file middlewareType=Tap
Enter fullscreen mode Exit fullscreen mode

That's the line to alert on in production: middlewareType=Tap plus Unable to send the. There's no counter or metric for it that I could find in this release candidate, only the log line, so anyone deploying tap with rejectOnRecordError: false needs log-based alerting or they will not notice their audit trail has silently stopped.

The documented size limit only limits what's recorded, not what's served

maxRecordBodySize caps how much of the body ends up in the JSON record, with the remainder marked bodyTruncated: true. I sent a 200,001-byte POST body through a route with maxRecordBodySize: 65536.

The record the tap service received held exactly 65,536 bytes of (base64-encoded) body and "bodyTruncated":true. The request that actually reached whoami, separately, carried the full 200,001 bytes, confirmed by the Content-Length header whoami echoed back. The truncation setting is purely about the audit copy; it has no effect on the real request path, and does not act as a backdoor request size limit the way I half expected before testing it.

Under concurrency, the overhead doesn't stay fixed, it compounds

concurrent clients baseline mean baseline p95 tapped mean tapped p95
10 6.94ms 12.04ms 13.12ms 18.16ms
50 12.39ms 24.28ms 52.53ms 68.39ms
100 14.92ms 32.68ms 101.22ms 127.43ms

At 10 concurrent clients, tap added about 1.9x to mean latency. At 100, it was closer to 6.8x. The untapped baseline also degrades under load, as any server does, but the tapped route degrades faster, because every request is now also opening and completing two extra HTTP exchanges to the tap service, and those compete for the same connection pool as everything else Traefik is doing.

What I got wrong on the way

My first pass at the concurrency test showed something alarming: 50 concurrent clients against the tapped route produced a p95 of 1,844ms, nearly two seconds, against 23ms for the untapped baseline at the same concurrency. I was about to write that up as a serious scaling flaw in the RC.

It wasn't one. My tap receiver was a bare http.server.ThreadingHTTPServer, which inherits a default TCP accept backlog of 5 connections from socketserver.BaseServer. Fifty concurrent client requests meant up to a hundred near-simultaneous connections landing on the receiver, and most of them queued at the kernel socket level before Python ever saw them. I was benchmarking my own test harness's accept queue, not Traefik.

Setting request_queue_size = 512 on the receiver and rerunning produced the numbers in the table above, which are still a real and substantial slowdown, just not a nearly-2-second one. The lesson: when a reverse proxy with hundreds of real-world production users starts behaving two orders of magnitude worse than expected under a toy benchmark, the toy is the more likely suspect.

What the timeout actually buys you

The docs recommend keeping timeout short, as a way to bound the damage from a slow tap service. I tested that directly: receiver delay set to 2 seconds, timeout: 300ms.

With rejectOnRecordError: false, the request took 603ms and returned 200: the 300ms timeout fired for both the request-side and response-side record, back to back, and Traefik gave up on each and served the real response anyway. With rejectOnRecordError: true, the request took 301ms and returned 500: Traefik didn't even wait for the response-side timeout once the request-side one had already failed.

So the timeout does exactly what it claims: it caps the worst case at roughly 2 x timeout instead of however slow the tap service actually is. It does not get you to zero added latency, because both directions still wait out their own timeout before giving up.

What it costs beyond latency

A single docker stats sample isn't a profile, so treat this as a rough sketch rather than a measurement: Traefik's CPU usage went from about 6.6% during a burst of 300 plain requests to about 22.7% during the same burst against the body-recording route with 60KB payloads. Memory stayed flat at roughly 35MB in both cases. The truncation and streaming design seems to mean tap doesn't hold large bodies in memory, but it clearly does more CPU work marshalling and shipping them.

Run it yourself

docker network create tapnet
docker run -d --name whoami --network tapnet traefik/whoami
docker run -d --name tapreceiver --network tapnet \
  -v "$PWD/tap_receiver.py:/app.py" python:3.12-slim python3 /app.py
docker run -d --name traefik_tap --network tapnet -p 18080:80 \
  -v "$PWD/traefik.yml:/etc/traefik/traefik.yml" \
  -v "$PWD/dynamic.yml:/etc/traefik/dynamic.yml" \
  traefik:v3.8.0-rc.1
Enter fullscreen mode Exit fullscreen mode

A minimal tap receiver, standard library only:

# tap_receiver.py
import time
from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer

class Handler(BaseHTTPRequestHandler):
    def do_POST(self):
        length = int(self.headers.get("Content-Length", 0))
        self.rfile.read(length) if length else None
        self.send_response(200)
        self.end_headers()

class Server(ThreadingHTTPServer):
    request_queue_size = 512  # the default of 5 will give you fake numbers

Server(("0.0.0.0", 9000), Handler).serve_forever()
Enter fullscreen mode Exit fullscreen mode

The router and middleware, as a dynamic.yml for Traefik's file provider:

http:
  routers:
    tapped:
      rule: "PathPrefix(`/tapped`)"
      service: whoami
      middlewares: ["tap-fast"]
  services:
    whoami:
      loadBalancer:
        servers: [{url: "http://whoami:80"}]
    tapsvc:
      loadBalancer:
        servers: [{url: "http://tapreceiver:9000"}]
  middlewares:
    tap-fast:
      tap:
        request: {service: tapsvc, path: /req, timeout: 5s}
        response: {service: tapsvc, path: /resp, timeout: 5s}
Enter fullscreen mode Exit fullscreen mode

Then compare curl -w '%{time_total}\n' -o /dev/null -s http://localhost:18080/plain against the same call on /tapped, repeated a few dozen times.

What to do with this

If you're weighing tap for audit logging on a route that matters, don't put it on a path where tail latency is the thing you get paged for, at least not in this release candidate, and not with rejectOnRecordError: true unless your tap endpoint is more available than the service you're protecting it for. Keep timeout low regardless of which way rejectOnRecordError is set, since it's the only knob that bounds the worst case. And if you do turn it on, set up log-based alerting on middlewareType=Tap errors now, because a silently dead audit trail is the kind of thing nobody notices until someone asks for logs that were never written.

Top comments (0)