A request id that survives the boundary

A request id is the cheapest observability you will ever buy and the first thing most systems get subtly wrong. It is not tracing, it is not metrics, and it will not tell you why something is slow. What it does is answer the only question that matters at two in the morning: show me everything that happened because of this one request.

Getting that right across a Java core, a Python service, and a queue that runs work minutes later took three decisions we would not have predicted.

The generator

One filter, running once per request, putting an id into the logging context and taking it out again:

String requestId = UUID.randomUUID().toString();
request.setAttribute(REQUEST_ID_ATTRIBUTE, requestId);
MDC.put(MDC_KEY, requestId);
try {
    filterChain.doFilter(request, response);
}
finally {
    MDC.remove(MDC_KEY);
}

The finally is not defensive habit. Logging context in Java is thread-local, and application servers reuse threads across requests. Forget the removal and the id leaks onto the next unrelated request handled by that thread — which is worse than having no id at all, because now your logs are confidently wrong. A missing correlation id is an inconvenience. A false one sends you to read the wrong user’s request.

The same id is also set as a request attribute, so the error handler can put it in the response envelope. That is the part users see: an error carries an identifier the person reporting it can quote, and it maps to exactly one log query.

The two-key trick

The Java service logs the field as requestId. The Python service emits correlation_id. Two services, two conventions, and the whole point of a correlation id is a single query across both.

The obvious fix is to rename one of them. We did not, and the reasoning is worth spelling out because it is the kind of tradeoff that gets made badly. Existing log patterns, dashboards, and saved queries reference the Java field name. Renaming it breaks every one of those on the day of the deploy, in exchange for cosmetic consistency.

So the filter publishes the same value under both keys. One id, two field names, nothing downstream breaks, and a cross-service query works today rather than after a migration nobody has time for.

Consistency is worth paying for. It is not worth paying for twice, once in the rename and once in everything the rename broke.

The decision that is easy to get backwards

Here is the one that separates a correlation id that works from one that looks like it works. When a request enqueues background work, when is the id captured?

The intuitive answer is: when the worker claims the job. That is where the log line is written, after all. It is also wrong, and it fails silently. By the time a worker claims a job the originating request finished long ago — possibly minutes ago, on a different thread, in a different process. Its logging context is empty. You get a job that logs an id belonging to whatever happened to be running when the worker woke up, or no id at all.

So the id is read at enqueue time, while the request is still on the stack, and stored on the row:

// Captured at enqueue time, not claim time: by the time a worker
// claims the job the originating request is long gone.
String correlationId = MDC.get(RequestIdFilter.MDC_KEY);

insert into job_queue
  (id, queue_name, payload, status, available_at, correlation_id)
values (?, ?, ?::jsonb, 'PENDING', now(), ?)

The column is nullable on purpose, because scheduled work has no originating request and pretending otherwise would mean inventing an id that points at nothing. Null is the honest answer to “which request caused this?” when the answer is “none, a clock did.”

The payoff is that a user’s click and the job it triggers eleven minutes later appear in one query, across two languages and a database table. That is the whole feature, and it is perhaps forty lines of code.

The bug: a filter that ran twice

The war story, because it teaches more than the design does.

The filter is constructed and wired explicitly rather than annotated as a component. That looks like an inconsistency in a codebase where everything else is annotated, and the comment explaining it is longer than the class.

The reason: Spring Boot auto-registers any bean implementing the servlet Filter interface into the container’s own global filter chain. Wire it into the security filter chain as well and it exists in two chains, running twice per request — generating one id, then overwriting it with a second. Half the log lines for a request carry one id and half carry another, which is the precise failure a correlation id exists to prevent.

Two general lessons sit inside that. First, a framework’s convenience feature and your explicit wiring can both be correct and still compose into a bug; the bug lives in the interaction, not in either piece. Second, this class of defect never fails a test and never throws. It degrades a signal, quietly, and the only way it gets caught is someone reading logs carefully enough to notice two ids where there should be one.

Observability code fails silently by nature. Nothing alerts you when your alarm system is the broken part.

What this deliberately is not

This is not distributed tracing. There are no spans, no parent-child relationships, no timing breakdown, and no flame graph. Those things are valuable and we do not have them.

What we have is roughly eighty percent of the practical benefit for about two percent of the operational cost, which is the correct trade at our size. Adopting a tracing stack before you have a request id working properly is the observability equivalent of buying a broker before you have a queue: real technology, applied to a problem you have not yet demonstrated.

Own every layer.