Reported symptoms
A customer says an order was picked twice. You have the order ID, and the fulfilment platform stamps it on every span, so you search Tempo for it and open the trace.
The trace has four spans. edge-gateway accepted the request,
order-api validated it, order-api wrote to Postgres, order-api
returned 202. Then it stops. The warehouse did the picking - there is a
picklist with a timestamp, and warehouse-api has its own logs for it -
but none of that is in this trace.
That is the report. The estate around it is stranger than the report.
- There is a second trace, and it is not broken. Searching Tempo by the
same order-ID attribute returns another trace under a completely different
ID. It starts about forty milliseconds after the first one ends and it
contains
warehouse-api,picking-service, and the whole picking flow, correctly nested, correctly parented, complete. On its own it looks like a textbook trace. warehouse-apihas no callers. The Grafana service-graph view has shown it as a service that receives traffic from nowhere for as long as anybody remembers. It has been written off as a metrics-generator quirk.- Tempo stores about 2.3 traces per front-door request. Capacity planning has never been able to explain the multiplier and eventually stopped trying.
- The logs pivot half works. Clicking through from a trace to Loki
returns
edge-gatewayandorder-apilines and nothing fromwarehouse-api. Someone raised that as a derived-fields bug and it was closed with “the Loki labels are correct”, which was true. stock-cacheemits thousands of one-span traces an hour. That is tracked separately, as a service that was never instrumented properly.- Staging is fine. An end-to-end request through staging produces one trace with every span in it. It has done so every time anyone has checked, for two years.
- Somebody already fixed this. Two weeks ago
traceparentwas added to the service-mesh header allow-list, on the theory that the sidecar was stripping it. Nothing changed.
The hypotheses on the whiteboard are: the mesh is stripping the header,
warehouse-api is not instrumented, the collector is dropping the
warehouse spans, and there is a sampling rule nobody can find. Each one
explains part of this and none of them explains the second trace being
perfect.
Evidence provided
Start where the last person stopped: is the header actually on the wire?
$ kubectl exec -n fulfilment deploy/order-api -- curl -sv http://warehouse-api:8080/healthz 2>&1 | grep -i 'traceparent'> traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01Illustrative output
And on the receiving side, inside the pod that is supposed to read it:
$ kubectl exec -n fulfilment deploy/warehouse-api -- tcpdump -A -s0 -i any 'tcp port 8080' 2>&1 | grep -i 'traceparent'traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01Illustrative output
So the network is clear, the mesh is clear, and the allow-list change two weeks ago was a correct action taken against the wrong hypothesis. Ask the receiver whether it did anything with what it received:
$ kubectl exec -n fulfilment deploy/warehouse-api -- curl -s http://127.0.0.1:9464/metrics | grep 'remote_parent'otel_sdk_span_started_count{parent="remote_parent"} 0Illustrative output
That is the whole incident in one line, and it takes some staring at. The SDK
is running and its spans are in Tempo by the million. It has never once
started a span as the child of something outside this process, despite a
well-formed traceparent arriving on every request.
The attribute spelling for this counter has moved between SDK versions, so confirm what your own build exports rather than copying the string above - but whatever it is called in your estate, this is the only place the answer lives.
Now look at how the two services are configured, side by side:
$ kubectl get deploy -n fulfilment order-api warehouse-api picking-service stock-cache -o jsonpath='{range .items[*]}{.metadata.name}{"\t"}{range .spec.template.spec.containers[0].env[?(@.name=="OTEL_PROPAGATORS")]}{.value}{end}{"\n"}{end}'order-api
warehouse-api b3multi
picking-service b3multi
stock-cache Illustrative output
Confirm it on the wire in the other direction - what warehouse-api sends
when it calls picking-service:
$ kubectl exec -n fulfilment deploy/picking-service -- tcpdump -A -s0 -i any 'tcp port 8080' 2>&1 | grep -iE 'traceparent|x-b3-'X-B3-TraceId: 9d1a7c4e2b83f05a6e7d1c9b4a20f831
X-B3-SpanId: 5b8aa5a2d2c872e8
X-B3-Sampled: 1Illustrative output
And the change that put it there, which is older than anyone expected:
# Substitute your own release name and namespace before running:
RELEASE=warehouse-api
NS=fulfilment
# What is actually set in production, versus what the chart defaults to.
helm get values "$RELEASE" -n "$NS" | grep -A2 -i propagator
helm get values "$RELEASE" -n staging | grep -A2 -i propagator
Production carries the variable. Staging does not - the staging values file was regenerated from chart defaults during a cleanup, and nobody noticed that it had stopped matching production.
One more thing, from the mesh change that was supposed to be the fix:
# The allow-list, as it stood before traceparent was added to it.
x-request-id
x-b3-traceid
x-b3-spanid
x-b3-sampled
x-b3-parentspanid
Work the evidence before reading on
The chain between two services has four separable links: the sender injects, the network carries, the receiver extracts, and the receiver parents its span on what it extracted. Three of them are cleared above.
traceparentis present on the outbound request and present on the inbound one. Which links does that clear - and be precise about what it does not clear.- The receiver has created millions of spans and not one of them has a remote parent. What single class of cause produces “the header arrived and the receiver started a new trace anyway”?
- The second trace is complete and correctly parented across two services. A stripped header, a broken SDK or a dropping collector would not produce that. What kind of fault produces two healthy traces instead of one damaged one?
stock-cacheemits only one-span traces at a rate matching the warehouse call rate. It is configured identically toorder-api, which is fine. Why would a correctly-configured service be the one that looks broken?- Staging works. Before you read on, decide whether that is evidence about the code, about the cluster, or about neither.
And the question worth answering before anything else: the mesh allow-list
contained four x-b3-* entries before anyone touched it. What was that
telling you, and how long had it been telling you?
Root cause
1. The header arrived and nobody read it
A propagator is not a parser that runs on whatever headers show up. It is a
list of named extractors, and each one looks for the specific header names
its format defines. OTEL_PROPAGATORS=b3multi gives the SDK exactly one
extractor, and that extractor looks for X-B3-TraceId, X-B3-SpanId and
X-B3-Sampled. It does not look at traceparent, because nothing told it
to.
So the request arrives at warehouse-api carrying a perfect W3C header, the
B3 extractor finds no B3 headers, extraction returns an empty context, and
the SDK does the only thing it can do with a request that appears to have no
parent: it starts a new trace with a new trace ID. There is no error. There
is nothing to log. From inside the process, this request looks exactly like a
request that arrived from outside the estate.
That is why the packet capture was so misleading. It proved the header
crossed the boundary, which everybody then read as proof that propagation
worked. A header on the wire is evidence about the network. Whether the
receiver has an extractor registered for that header name is a completely
separate fact, and otel_sdk_span_started with parent="remote_parent"
flat at zero is the statement of it.
2. Two healthy traces, not one broken one
This is the part that kept four people busy.
warehouse-api does not only extract B3, it also injects B3, because the
propagator list governs both directions. So when it calls
picking-service, it writes X-B3-* headers, and picking-service - also
pinned to b3multi - extracts them correctly and parents its span properly.
The result is a second trace that is not damaged in any way. It is coherent, correctly nested, and complete for everything from the warehouse onwards. It is a perfectly good trace of the wrong scope.
That defeats every heuristic the team had. A single-span-trace alert would not fire, because these traces have many spans. A “trace is truncated” check would not fire, because neither trace is truncated - each one ends exactly where its scope ends. A dashboard of per-service span rates looks correct, because every service is emitting the spans it should. The estate is not producing broken data. It is producing two accurate answers to a question nobody asked.
3. stock-cache is the one service that is configured correctly
stock-cache runs the SDK default, tracecontext,baggage. It is called by
warehouse-api, which now sends only B3. So stock-cache receives headers
it has no extractor for, finds no parent, and starts a root span. It has no
downstream calls, so that root span is the entire trace.
Thousands of one-span traces an hour, at a rate that matches the warehouse
call rate. It was filed as “stock-cache was never instrumented properly”,
which is the exact opposite of the truth: stock-cache is the only service
in the chain whose propagation configuration nobody broke. It looks worst
because it is downstream of the break and running the correct format.
4. The multiplier, the orphan and the half-dead pivot
Once you have the mechanism, four unrelated tickets collapse into one line.
Each front-door request now produces the gateway/order trace, the
warehouse/picking trace, and one stock-cache trace per cache lookup. That
is the 2.3 multiplier that capacity planning could never explain - it is not
retry traffic and it is not double instrumentation, it is one request being
recorded as several unrelated stories.
The service graph is built from parent-child relationships between spans.
warehouse-api has no callers in the graph because, in the data, it has no
callers: every span it ever created was a root or the child of one of its
own. The graph was not glitching. It was reporting the data faithfully.
The trace-to-logs pivot filters Loki by the trace ID of the trace you are
looking at. warehouse-api writes its own, different trace ID into its log
lines, so filtering by the gateway’s trace ID correctly returns nothing.
The Loki labels were fine. The ticket was closed accurately and the
underlying observation was thrown away.
5. Staging never tested this
The staging values file does not set OTEL_PROPAGATORS, so staging runs the
chart default, which is W3C. Staging has been correct all along and has
therefore never been able to reproduce the fault.
Two years of “but it works in staging” was not a weaker test of the same system. It was a correct test of a different one, and every time it passed it pushed the investigation further downstream.
Resolution
- Confirm the diagnosis for the cost of one restart, before changing anything permanently. Roll a single warehouse-api pod with OTEL_PROPAGATORS set to tracecontext,baggage, send one request through the front door, and check whether the remote-parent counter on that pod moves off zero. If it does, every downstream hypothesis on the whiteboard is closed.
- Enumerate the remaining B3 consumers before you touch anything shared. Sources: the four x-b3-* entries on the mesh allow-list, the list of services that came from the Zipkin estate, and a capture of what is actually on the wire between internal services. Write the list down; the absence of a list is the root cause behind the root cause.
- Bridge, do not flip. Set OTEL_PROPAGATORS to tracecontext,baggage,b3multi on warehouse-api and picking-service. Both formats are injected on every outbound call and both are accepted inbound, so no boundary in the estate is the wrong way round during the transition.
- Decide which format is authoritative if both headers ever arrive together, and write that decision down next to the configuration. In a mixed estate with a legacy proxy this is not theoretical, and propagator ordering is not a thing to leave to whoever edits the values file next.
- Put a date and an owner on the removal of b3multi. A migration state with no end date is the configuration, and this incident is what that looks like two years later.
- Do not add b3multi to the senders and call it done. It stitches the trace tonight and standardises the estate on the format you are trying to leave, so every service built afterwards inherits the problem.
- Do not translate headers at the mesh. Rewriting one format into the other in a middlebox makes the trace correct and moves the reason into a layer that no service owner will ever think to check.
- Move OTEL_PROPAGATORS out of the per-service values files and into the fleet-level default, so that a service-specific override becomes something a reviewer has to approve rather than something inherited.
- Reconcile staging with production in the same change. Staging is currently correct by accident, which means it is not testing production and has not been for two years.
- If you hold rather than fix - and holding is defensible, because nothing here is customer-facing - hold with an owner and an end date, and write into the warehouse-api runbook that its spans live under a separate trace ID reachable by the order-ID attribute. The cost of this bug is paid in incident-response minutes, and an undocumented hold makes the next incident more expensive, not less.
Verification
- Verify that the receiver extracted, not that the header arrived. traceparent has been arriving correctly throughout, so a wire check would have passed for the entire two years. The signal is otel_sdk_span_started with parent="remote_parent" at warehouse-api moving off zero and then tracking the inbound request rate.
- Check what your SDK build actually exports before writing that alert. The metric and attribute spelling has moved between versions, and an alert on a name that does not exist is green forever.
- Verify one journey by identity. Take a trace ID from an edge-gateway log line, fetch that trace from Tempo, and require the picking-service span to be inside it. "A picking-service span exists somewhere in Tempo" was true throughout the incident and is not the claim you are testing.
- Prove the check can fail. Send one request to a pod still carrying the old propagator value and confirm the second trace still appears. A verification that has never gone red is an assumption with a dashboard.
- Verify the population, not the sample. The ratio of stored traces to front-door requests should fall from roughly 2.3 towards 1. That ratio is the independent statement that the estate has stopped manufacturing a second trace per request, and any residual is a hop you have not found.
- Confirm the stock-cache one-span traces stop, at the rate they were being produced. That closes a ticket filed as unrelated and confirms the fix reached the far side of the warehouse.
- Confirm warehouse-api acquires a caller in the service graph. The graph is built from parent-child relationships, so it is a direct readout of whether parenting is now happening.
- Confirm the trace-to-logs pivot returns warehouse-api lines from the same trace as the gateway lines, and close the Loki derived-fields ticket with the actual cause rather than leaving it closed as a non-issue.
- Verify what the fix could have broken. Check every service you identified as a B3 consumer and confirm it is still extracting a format it understands. If the bridge was skipped, this is where the damage is, and it looks exactly like the fault you have just spent a day diagnosing.
- Re-check after the bridge is removed, not only after it is added. The day b3multi comes off both ends is a second cutover with the same failure mode, and it will happen weeks later when nobody is watching.
Prevention
- Standardise on one propagation format across the estate, and treat any interop period as a dated migration with an owner. B3 was never the problem. An undated pin was.
- Set the propagator list at the fleet level. A per-service
OTEL_PROPAGATORSshould be an override a reviewer approves, not a value inherited from a values file written by a team that no longer exists. - Put a propagation contract test in CI: issue a request across the boundary and assert the child span carries the parent’s trace ID. It is the only check that survives a refactor, and it would have caught this on the day the pin was written.
- Alert on shape, not on absence. The ratio of stored traces to front-door requests is a whole-estate detector for propagation splits, and a per-service rate of root spans names the service that is starting traces it should have joined. Both signals existed here for two years, unwatched.
- Do not let a passing staging test stand in for evidence about production when the two are configured from different files. An environment that differs by an inherited value is a different system.
- Treat a header on the wire as evidence about the network and nothing else. Whether the receiving SDK has an extractor registered for that header name is a separate question with its own separate answer.
- Read the exemptions. Four
x-b3-*entries sitting on a mesh allow-list is a fossil of an earlier estate, and a fossil in a live configuration file is a question that nobody has asked recently enough.