Orphaned spans are a propagation bug, not a latency bug

The tool executor was made concurrent on 4 February, in a change titled "run independent tool calls in parallel". It was a good change: the agent frequently asks for three tools at once, they had been running one after another, and the median request lost about 1.6 seconds per step to that. The change went out, p50 latency on /v1/answer — the median, the duration half the requests come in under — dropped from 11.4 to 7.6 seconds, and nobody looked at a trace tree in anger until 19 March, when an escalation arrived and the tree looked like this:

POST /v1/answer                          trace b71e…   7.61s   200
└─ agent.run  support_agent                            7.58s
   ├─ agent.step 1
   │  └─ chat claude-opus-5                            2.11s
   └─ agent.step 2                                     1.24s   (no children)

execute_tool lookup_order                trace 3d90…   0.31s   ok
execute_tool search_docs                 trace 88a1…   1.21s   ok
└─ db.query vector_search                              1.14s   ok

execute_tool lookup_account              trace f47c…   0.42s   ok

Three separate traces, each with its own root, each internally correct. A root is a span with no parent, which is what a tracer produces when it opens a span and finds no active one to attach to, and it is normally the one span per request that the HTTP layer emits. Here there are four of them, and the internal nesting inside each is exactly as intended — db.query sits under search_docs, because within a single tool call nothing crossed a boundary. Every duration is right. The agent.step 2 span has the right start time, the right end time and no children, and it has looked like that for six weeks: 42,000 requests a day for 44 days, about 1.8 million requests whose trajectories were recorded as four unrelated fragments each.

The only thing that broke was the edge#

Nothing that anyone watches moved. Span durations are measured from the span's own start and end, so they were unaffected. The error rate is computed per span from span status, and every one of these spans is OK. Endpoint latency comes off the HTTP span, which is still a single root covering the whole request. Token totals are computed by summing an attribute across spans matched on a name and a time range, and that query does not walk the tree at all, so cost reporting stayed exactly correct. The trajectory fell apart in a way that touched no metric anyone had chosen to alert on.

There was a signal, and it was sitting in plain view in the vendor's own usage page. Root spans per day went from about 42,000 to about 168,000 on 4 February, and average spans per trace fell from 21 to 5.2. Both are step changes on the day of the deploy. Neither had a chart, because "number of traces" reads like a billing statistic rather than a correctness one.

That is the detector worth building, and it is one query: count spans where the parent span id is empty and the span name is not your HTTP server span name. On a healthy system that count is zero. Alert on it being non-zero for more than a few minutes and you catch this class of bug on the afternoon it ships rather than in the seventh week.

Where the context actually stops#

The commit message says asyncio.gather, and asyncio.gather is not what broke it — which is why the diagnosis took longer than it should have. When you call asyncio.create_task or gather on a coroutine, Python copies the current contextvars context into the new task at creation time — contextvars being the standard-library store for values that are local to the running task or thread rather than global to the process, which is how a library keeps track of "the request being handled here" without you passing it around — and OpenTelemetry's current span lives in a context variable, so the active span propagates into the task correctly. A straightforward await asyncio.gather(*(dispatch(c) for c in calls)) inside the step span produces exactly the tree you wanted.

What the change actually introduced was a bounded worker pool, because unbounded fan-out onto a rate-limited internal API had caused an incident the previous quarter. Four worker tasks are created at application startup; they loop forever reading WorkItems off an asyncio.Queue; the agent step puts items on the queue and awaits their futures. The context copy still happens — at the moment the worker task was created, which was during startup, when there was no active span and no trace at all. Every tool span therefore starts from an empty context, which is precisely the situation in which a tracer mints a new trace id and a root span.

The same shape appears wherever work is handed to something that was not created inside the span. A synchronous provider SDK dispatched with loop.run_in_executor is the other common one: run_in_executor does not copy the calling context into the worker thread, while asyncio.to_thread does, and the two are near-synonyms in most people's heads. A ThreadPoolExecutor.submit from a Flask handler, a Celery task, a callback registered on a connection pool, and a background task started with asyncio.create_task before the span was opened all fail the same way.

The fix is to carry the context explicitly across the boundary, which the API is designed for. Capture it where the work is created and attach it where the work runs:

from opentelemetry import context as otel_context, trace

tracer = trace.get_tracer("assist.support_agent")


async def submit(queue: asyncio.Queue, call: ToolCall) -> asyncio.Future:
    future = asyncio.get_running_loop().create_future()
    # snapshot of the caller's context, including the active agent.step span
    await queue.put(WorkItem(call=call, future=future,
                             otel_context=otel_context.get_current()))
    return future


async def worker(queue: asyncio.Queue) -> None:
    while True:
        item = await queue.get()
        token = otel_context.attach(item.otel_context)
        try:
            with tracer.start_as_current_span(f"execute_tool {item.call.name}") as span:
                span.set_attribute("tool.call_id", item.call.id)
                item.future.set_result(await dispatch(item.call))
        except Exception as exc:
            item.future.set_exception(exc)
        finally:
            otel_context.detach(token)
            queue.task_done()

For a thread boundary the equivalent is contextvars.copy_context().run(fn), or handing the executor a functools.partial built inside a copied context. In both cases the object being moved is the whole context — the trace id, the span id of the parent, the baggage (arbitrary key-value pairs, such as a tenant id, that ride along with the trace ids wherever they go), and anything else any library has put there.

Threading the trace id rebuilds half of a mechanism you already have#

The proposal that shows up in review is to add a trace_id: str parameter to the tool interface, pass it through the queue, and set it on the span in the worker. It is appealing because it is small, explicit and typed, and because the thing that is missing does appear to be a trace id.

It fixes about a third of the problem. A trace id gets the tool span into the right trace; a parent-child edge needs the span id of the step, which is the field that carries "which step, which attempt". With only the trace id threaded through, the tool spans stop being separate traces and become additional roots inside one trace — better, in that a query for the run now returns them, and still unable to say which of two agent.step spans a given tool call belonged to, or whether two identical execute_tool lookup_order spans are one call retried or two calls the model made deliberately. That last distinction is the one that matters most often and it is exactly the one the edge encodes.

Three further costs come with it. Every tool signature changes, including tools you do not own — a third-party client, a tool reached over MCP (the Model Context Protocol, which puts the tool behind a server you do not own), a function contributed by another team — so the mechanism cannot be complete. Any instrumentation inside the tool still reads the ambient context rather than your parameter, so the HTTP client library, the database driver and the vector store client will all parent their spans to whatever the worker's context holds, which is nothing; you will have fixed the tool span and orphaned everything beneath it. And you now maintain a second, partial propagation mechanism alongside the real one, which the next person will have to discover, and which will silently not apply to whatever gets added next.

The W3C traceparent format already encodes the trace id and the parent span id together in one string, every OpenTelemetry instrumentation reads and writes it, and the in-process Context object is its local equivalent. Propagation is a solved problem with a standard; the bug is that this code path skipped it, and the fix is to stop skipping it rather than to write a smaller version of it.

Serialising pays for a telemetry bug with product latency#

The other reflex — revert to sequential tool execution until the framework is fixed — correctly identifies that execution context is involved and then buys the fix with the feature. Three tools taking 0.9, 1.2 and 0.7 seconds cost 1.2 seconds concurrently and 2.8 seconds serially, and at an average of 2.4 tool-using steps per request that is about 3.8 seconds added to a 7.6-second p50. Half the request's latency, given back, to correct an attribute on a span.

It also does not hold. The propagation break is not a property of concurrency; it is a property of work starting in a context that was captured somewhere else. Serialising the tool executor removes today's instance and leaves the mechanism in place, so the same trees reappear the first time anything is scheduled onto a thread pool, a queue consumer or a background task — which, on a service that talks to a rate-limited internal API, will be soon.

What six weeks of orphans are still good for#

The spans exist. They carry names, durations, statuses, tool names, timestamps, and — because the correlation ids from chapter 1 were set on every span rather than only on the root — a tenant id and a session id. Everything that is a fact about one span survives, so per-tool latency distributions, tool error rates, and cost by tenant are all unaffected for the whole six weeks.

What is gone is everything that was a fact about the relationship between spans, and it cannot be recomputed, because the parent span id was never written. A partial reconstruction is available through the correlation ids: filtering every span by session.id and ordering by start time gives you the sequence of what happened in a run, which is a flat log with better attributes — enough to answer "what did this run do", not enough to answer "how many attempts did step 2 take" when two attempts overlap in time or when the run made the same tool call twice for different reasons.

Whether that matters is a narrower question than it first appears. Nobody re-analyses six weeks of old traces on their merits; traces are read during incidents, and those incidents are over. The real cost was paid at the time, in six weeks of investigations conducted with degraded data, and the honest follow-up is to re-check any conclusion from that window that turned on an attempt count or a step attribution — in practice, two postmortems — and then to fix the retention policy so that the fragments age out rather than being migrated forward as though they were usable history.

Which leaves a system whose trajectories are intact and whose spans carry content. That is enough to answer a question that a request log by itself cannot touch, and the next chapter takes the ordinary version of that question: a customer says a reply took 45 seconds and arrived cut off, and the access log has exactly one line about it.