[Bug]: OTEL "Dynamo bytecode transform" span reports wildly incorrect duration (tens of thousands of days)

[nicklasfrahm]

🐛 Describe the bug

When OpenTelemetry tracing is enabled (--otlp-traces-endpoint), the Dynamo bytecode transform span emitted from torch.compile instrumentation reports a wildly incorrect duration — tens of thousands of days instead of the actual compile time (seconds).

Example span observed in a trace backend:

Dynamo bytecode transform
Service: llm
Duration: 20622d 20h
Start Time: 0μs (01:51:02.838)
Kind: internal
Status: unset
Library Name: vllm.tracing.otel

Span attributes
dynamo.time_seconds   17.16094771400094

The dynamo.time_seconds attribute (17.16s) is correct, but the span's own start/end timestamps used for the rendered Duration are off by ~56 years (~20622 days), which matches the gap between the Unix epoch and "now".

Root cause

In vllm/compilation/backends.py (around line 1145-1156):

from .monitor import torch_compile_start_time

dynamo_time = time.perf_counter() - torch_compile_start_time
...
start_time = int(torch_compile_start_time * 1e9)
attributes = {"dynamo.time_seconds": dynamo_time}
instrument_manual("Dynamo bytecode transform", start_time, None, attributes)

torch_compile_start_time is set in vllm/compilation/monitor.py:

torch_compile_start_time: float = 0.0
...
def ...():
    global torch_compile_start_time
    torch_compile_start_time = time.perf_counter()

time.perf_counter() returns a value from a monotonic clock with an arbitrary, implementation-defined reference point (e.g. system boot time on Linux). It is only meaningful for measuring elapsed intervals via subtraction — it is not wall-clock/Unix-epoch time.

However, instrument_manual forwards start_time directly into OpenTelemetry's tracer.start_span(start_time=...) (see vllm/tracing/otel.py::manual_instrument_otel), which expects nanoseconds since the Unix epoch:

span_kwargs: dict[str, Any] = {
    "name": span_name,
    "context": ctx,
    "start_time": start_time,
}
...
span = tracer.start_span(**span_kwargs)
...
span.end()  # end_time is None here, so OTel uses the real wall-clock "now"

Because end_time is None, span.end() stamps the end time using the real wall-clock time.time_ns(). So the span ends up with:

• start_time ≈ perf_counter() value (small, interpreted as if it were close to the 1970 epoch)
• end_time ≈ actual wall-clock now

The resulting duration is therefore roughly "now minus 1970", i.e. tens of thousands of days, regardless of how long Dynamo actually took to compile.

Suggested fix

Anchor the span timestamps to wall-clock time instead of the monotonic clock, e.g. capture both a monotonic start (for the elapsed delta) and a wall-clock reference in vllm/compilation/monitor.py, and compute the OTel start_time from wall-clock time at the call site in vllm/compilation/backends.py, for example:

# monitor.py
torch_compile_start_time: float = 0.0       # time.perf_counter()
torch_compile_start_time_wall: float = 0.0  # time.time()

# backends.py
dynamo_time = time.perf_counter() - torch_compile_start_time
start_time_wall = torch_compile_start_time_wall  # seconds, epoch-relative
start_time = int(start_time_wall * 1e9)
end_time = int((start_time_wall + dynamo_time) * 1e9)
instrument_manual("Dynamo bytecode transform", start_time, end_time, attributes)

This would also let other callers of instrument_manual avoid the same pitfall if they pass a time.perf_counter()-derived value by mistake.

Impact

Any OTel trace viewer (Jaeger, Tempo, etc.) shows the Dynamo bytecode transform span with a nonsensical multi-decade duration, which is confusing/misleading for anyone using tracing to debug compile-time overhead, and can visually break trace waterfalls/timelines in the UI (span extends far outside the rest of the trace).

Environment

Found via source inspection on vllm at commit 3b03a2cf4772838da622d81315941bb41bcc03ff (main, 2026-06-11). The bug is not environment-specific — it reproduces whenever --otlp-traces-endpoint is set and a torch.compile-triggered Dynamo bytecode transform occurs.

Before submitting a new issue...

• I searched for relevant existing issues (no existing report found for this specific span/duration bug).

---

Root cause and analysis above were investigated with AI assistance (Claude); the underlying source locations and reasoning were reviewed by me before filing.

[nicklasfrahm]

Update: confirmed root cause and found two existing open PRs that attempt to fix the same span (both unmerged):

• [BugFix] Correct OTEL span start time for Dynamo compilation #40698 — [BugFix] Correct OTEL span start time for Dynamo compilation. Computes start_time = time.time() - dynamo_time and still relies on instrument_manual(..., end_time=None, ...) defaulting the span end to "now". Pre-commit/DCO pass, but it has sat without maintainer review for ~2 months and has no test coverage.
• Fix "Dynamo bytecode transform" span start time calculation #44909 — Fix "Dynamo bytecode transform" span start time calculation. Same idea as a 1-line change (start_time = int((time.time() - dynamo_time) * 1e9)). Currently CI-broken: DCO check is ACTION_REQUIRED (missing sign-off) and the pre-run-check / pre-commit checks are failing.

Both fixes correct only start_time, and both rely on the implicit assumption that no measurable time passes between computing dynamo_time and the instrument_manual call (so that span.end() with no explicit end_time lands close enough to the true end). That's true today, but fragile to future refactors of that code path.

I'm opening a PR that:

• Anchors the span to a wall-clock reference captured once, at the actual start of monitor_torch_compile (vllm/compilation/monitor.py), rather than reconstructing "start = now - elapsed" right before emitting the span.
• Passes an explicit end_time to instrument_manual instead of relying on the implicit "ends now" default.
• Adds a regression test (tests/tracing/test_loading_tracing.py) asserting the span's start_time_unix_nano/end_time_unix_nano land near wall-clock "now" rather than near the Unix epoch — neither existing PR has test coverage for this.

Will link the PR here once open.

[nicklasfrahm]

Opened #46194 with the fix described above.