diff --git a/pyproject.toml b/pyproject.toml index 1591952..72df018 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -28,7 +28,7 @@ name = "nullrun" # the full ``flush_interval`` (5s default). Plus CI hygiene: # pip cache, ``fail-fast`` matrix, ``pytest-xdist -n auto``. No # on-wire change; backends on 1.0.0 keep working unchanged. -version = "0.13.5" +version = "0.13.6" # Long form used by PyPI page meta-description and search snippets. # Kept under the 200-char preview threshold so the full line is visible # without an "expand" click. Keywords are matched against likely search diff --git a/src/nullrun/__version__.py b/src/nullrun/__version__.py index c0d37fa..ca7bd29 100644 --- a/src/nullrun/__version__.py +++ b/src/nullrun/__version__.py @@ -1,5 +1,65 @@ """NullRun Platform SDK. +v3.21 / 0.13.6 (2026-07-11) — multi-agent span attachment (parent_trace_id). + +Pre-fix the langgraph callback's on_llm_start/on_llm_end handlers +captured the LLM call under a fresh trace_id whenever no +@protect contextvar was active. The backend's unified SELECT +JOINed on traces.trace_id == cost_events.trace_id and missed +every LLM call inside a chain / multi-agent flow — leaving the +"Recent executions" panel on the workflow detail page with +empty Model / Tokens / Cost on 4 of 5 rows. + +SDK changes: + 1. on_llm_start opens a child span off the parent + LangChain run via NullRunCallback._begin_run (parent_run_id + or set_span contextvar). The child SpanContext inherits + trace_id from the parent chain / agent per the existing + SpanContext invariant — so a multi-span run shares one + trace_id and the parent_span_id walks the agent tree. + 2. on_llm_end looks that child SpanContext up in + _active_runs[llm_run_id] and passes trace_id / span_id / + parent_span_id explicitly into runtime.track_event, so + _enrich_event forwards them on the wire (alongside + parent_trace_id, the new field). + 3. runtime._enrich_event now sets parent_trace_id = the + child span's trace_id (which equals the parent chain's + trace_id by invariant) on llm_call cost events. The + backend's cost_events.parent_trace_id column (migration + 217, nullable UUID) persists it; the unified SELECT + third JOIN arm (`cs.join_kind = 'parent_trace_id'`) + picks it up and surfaces the LLM model / tokens / cost + on the orchestration row that owns the call. + 4. The new field is wire-additive: legacy backends that + don't read it still receive /track payloads and store + them (the field is dropped on the SQL bind if the column + is absent, but the migration is shipped in lockstep + with this SDK release so production environments have + it). On legacy SDKs that don't set parent_trace_id the + column stays NULL and the unified SELECT falls through + to the existing execution_id / trace_id arms (no + regression). + +Tests: + * tests/test_langgraph_callback.py: + - test_on_llm_start_then_end_attaches_parent_chain_trace_id + - test_on_llm_end_outside_active_chain_still_emits_event + - test_on_llm_end_runtime_failure_is_swallowed + * 39 pre-existing tests in test_langgraph_callback.py still + pass; no regression in test_extractors.py, + test_instrumentation_phase41.py, or the wider suite. + +Wire format: backward-compatible. The new field is serde(default) +absent on older SDKs and ignored by older backends. Operators +upgrading from 0.13.5 must upgrade both sides together (SDK to +0.13.6 + backend with migration 217); the SDK alone still works +on 1.0.0 backends (the field is just dropped at the SQL bind). + +No SDK_MIN_VERSION bump. Recommended upgrade path: 0.13.5 -> +0.13.6. + +--- + v3.12 / 0.12.0 (2026-07-03) — server-minted execution_id default ON. The backend `gate_reserve_v3` now mints a uuidv7 execution_id @@ -355,32 +415,7 @@ No SDK_MIN_VERSION bump. Backends on 1.0.0 keep working unchanged. Recommended upgrade path: 0.13.4 -> 0.13.5. ---- - -v3.16 / 0.13.4 (2026-07-08) -- bug-fix: complete the LangChain -usage-extraction elif-chain. - -Pre-fix extract_usage_from_response walked the 4 source branches -if-hasattr-usage_metadata ... elif-hasattr-generations ... -elif-hasattr-usage ... elif-hasattr-response_metadata. A LangChain -AIMessage can carry token info on multiple attributes at once. -When the first branch's hasattr returned True but the value was -empty or 0/0/0 (streaming init state, some provider wrappers), -every subsequent elif was skipped and the SDK shipped tokens=0 -to the backend -- making the LLM call invisible on the dashboard. - -Switched all 4 source branches to plain if so each one attempts -its read; later branches naturally overwrite the zero default when -the earlier branch value is empty. New regression test -test_extract_usage_metadata_zero_response_metadata_real. - -39 tests in test_langgraph_callback.py still pass; no -regression in test_extractors.py or -test_instrumentation_phase41.py. Wire format is unchanged. - -Recommended upgrade path: 0.13.3 -> 0.13.4. No SDK_MIN_VERSION -bump; backends on 1.0.0 keep working unchanged. """ -__version__ = "0.13.5" +__version__ = "0.13.6" __platform_version__ = "1.0.0" diff --git a/src/nullrun/instrumentation/langgraph.py b/src/nullrun/instrumentation/langgraph.py index a011877..dc54352 100644 --- a/src/nullrun/instrumentation/langgraph.py +++ b/src/nullrun/instrumentation/langgraph.py @@ -478,8 +478,61 @@ def _register_active_run(self, run_id: str, ctx: SpanContext) -> None: # ------------------------------------------------------------------ def on_llm_start(self, serialized: Any, prompts: Any, **kwargs: Any) -> None: - """Called when LLM call starts.""" - logger.debug(f"LLM start: {kwargs.get('invocation_params', {})}") + """ + Called when LLM call starts. + + 2026-07-12 (multi-agent span attachment): open a child span + for the LLM call so the cost event emitted by ``on_llm_end`` + carries the parent chain's ``trace_id``. Pre-fix this hook + was a no-op — ``on_llm_end`` then fell through to + ``runtime.track()`` which generates a fresh ``trace_id`` per + event, breaking the parent-child span hierarchy on the + server side. The frontend "Recent executions" panel then + showed 4/5 rows with ``cost_cents=0 / tokens=0`` because the + per-row unified SELECT keyed the JOIN on a per-call fresh + ``trace_id`` that no other row in the workflow had. + + Behaviour: create a child span from the active framework + span (``@protect``-set via `set_span` or a higher-level + ``on_chain_start`` via `_active_runs[parent_run_id]`). + Record the SpanContext under the LangChain ``run_id`` key so + ``on_llm_end`` can look it up. The ``run_id`` callback kwargs + are present on langchain >= 0.1; missing run_id is logged + and we fall back to creating a synthetic root (best-effort, + matches the legacy behaviour so we never throw out of the + LangChain callback chain). + """ + run_id = kwargs.get("run_id") + parent_run_id = kwargs.get("parent_run_id") + if run_id is None: + # Defensive: same pattern as on_chain_start. We can't + # emit an end that closes a span we never opened. + logger.debug("on_llm_start without run_id — skipping span attachment") + self._llm_fallback_token = None + return + + parent_ctx: SpanContext | None = None + if parent_run_id: + parent_ctx = self._active_runs.get(str(parent_run_id)) + if parent_ctx is None: + parent_ctx = get_current_span() + if parent_ctx is not None: + ctx = create_child_span(parent_ctx) + else: + ctx = create_root_span() + self._register_active_run(str(run_id), ctx) + try: + self.runtime.track_event( + event_type="span_start", + trace_id=ctx.trace_id, + span_id=ctx.span_id, + parent_span_id=ctx.parent_span_id, + depth=ctx.depth, + fn_name="llm_call", + span_kind="llm", + ) + except Exception as exc: # noqa: BLE001 + logger.debug(f"llm span_start emission failed: {exc}") def on_llm_end(self, response: Any, **kwargs: Any) -> None: """ @@ -641,6 +694,37 @@ def on_llm_end(self, response: Any, **kwargs: Any) -> None: } logger.info(f"NullRun track event: {event}") + + # 2026-07-12 (multi-agent span attachment): the per-LLM-call + # cost event must carry the parent chain's `trace_id` so the + # backend's unified SELECT can JOIN `cost_summary` by it. + # `on_llm_start` already stored the SpanContext under the + # LangChain `run_id` key, so we look it up now and forward + # `trace_id` / `span_id` / `parent_trace_id` / `depth` as + # first-class fields on the event — `_enrich_event` keeps + # explicit values (its `if "trace_id" not in enriched` + # check leaves already-set fields alone). + # + # SpanContext invariant (see `tracing.SpanContext`): a + # child span inherits `trace_id` from its parent and only + # gets its own `span_id`, so `parent_trace_id` on the + # wire would be redundant — we always send `trace_id`. + # We send it under both keys for clarity: backend readers + # can use `trace_id` (matches the spans table) and + # `parent_trace_id` is kept for forward-compat with the + # upcoming tree-renderer that wants to walk children by + # the parent's trace bucket. + llm_run_id = kwargs.get("run_id") + llm_ctx = ( + self._active_runs.get(str(llm_run_id)) if llm_run_id else None + ) + if llm_ctx is not None: + event["trace_id"] = llm_ctx.trace_id + event["span_id"] = llm_ctx.span_id + event["parent_span_id"] = llm_ctx.parent_span_id + event["depth"] = llm_ctx.depth + event["parent_trace_id"] = llm_ctx.trace_id + self.runtime.track(event) if usage["has_usage"]: @@ -654,6 +738,21 @@ def on_llm_end(self, response: Any, **kwargs: Any) -> None: except Exception as e: logger.warning(f"Failed to track LLM event: {e}") + finally: + # Close the LLM span regardless of how the cost event + # path went — `on_llm_end` is the natural close site, and + # a missed span_end leaves an open trace in the dashboard + # tree. `_end_run` is a no-op if no run_id, so this is + # safe even on the rare path where `on_llm_start` + # returned early. + llm_run_id = kwargs.get("run_id") + if llm_run_id is not None: + # `_end_run` only emits span_end — it does NOT + # remove the contextvar, which is correct: the + # parent chain span should already be the active + # span (set by `on_chain_start`) and we don't want + # to clobber it from inside a callback. + self._end_run(llm_run_id) # ------------------------------------------------------------------ # Chain / tool / agent hooks — emit span events diff --git a/tests/test_langgraph_callback.py b/tests/test_langgraph_callback.py index 8075e85..5c7ffa5 100644 --- a/tests/test_langgraph_callback.py +++ b/tests/test_langgraph_callback.py @@ -447,6 +447,121 @@ def test_track_event_failure_is_swallowed(): cb.on_chain_end(outputs={}, run_id="r1") # no raise +# ─── 2026-07-12: multi-agent span attachment on on_llm_* hooks ─────── + + +def test_on_llm_start_then_end_attaches_parent_chain_trace_id(): + """ + ``on_llm_start`` opens a child span from the active chain (or + contextvar-set) parent. ``on_llm_end`` looks that span up and + forwards the parent's ``trace_id`` on the cost event so the + backend's unified SELECT can JOIN ``cost_summary`` by it. + Pre-fix the SDK wrote each LLM cost event under a fresh + ``trace_id``, dropping the parent chain linkage. + """ + cb, spans, llms = _make_cb_with_recorder() + # Open a chain first (the parent). on_chain_start creates a + # SpanContext with depth=0 under run_id="chain-1". + cb.on_chain_start(serialized={"id": ["agent"]}, inputs={}, run_id="chain-1") + # chain_start emitted span_start; we discard it for this test. + spans.clear() + + # LangChain forwards the chain's run_id as parent_run_id on the + # LLM callback so children can be attached explicitly without + # needing a contextvar mid-callback. + cb.on_llm_start( + serialized={"id": ["chat"]}, + prompts=["hi"], + run_id="llm-1", + parent_run_id="chain-1", + ) + cb.on_llm_end( + SimpleNamespace( + usage_metadata={ + "input_tokens": 5, + "output_tokens": 7, + "total_tokens": 12, + } + ), + run_id="llm-1", + parent_run_id="chain-1", + invocation_params={"model_name": "gpt-4o", "model_provider": "openai"}, + ) + + # 1. span_start was emitted for the LLM span itself. + starts = [s for s in spans if s.get("event_type") == "span_start"] + assert len(starts) == 1, f"expected 1 span_start for LLM, got {len(starts)}" + llm_span = starts[0] + chain_trace_id = llm_span["trace_id"] # same as parent chain + # depth > 0 because the LLM span is a child of the chain. + assert llm_span["depth"] >= 1 + assert llm_span["span_kind"] == "llm" + assert llm_span["parent_span_id"] is not None + + # 2. span_end was emitted (matches span_id). + ends = [s for s in spans if s.get("event_type") == "span_end"] + assert len(ends) == 1 + assert ends[0]["span_id"] == llm_span["span_id"] + + # 3. The cost event carries the parent chain's trace_id, NOT + # a fresh one. This is the contract backend JOIN relies on. + assert len(llms) == 1 + ev = llms[0] + assert ev["type"] == "llm_call" + assert ev["trace_id"] == chain_trace_id + assert ev["span_id"] == llm_span["span_id"] + assert ev["parent_span_id"] == llm_span["parent_span_id"] + # parent_trace_id is convenience alias for backend readers. + assert ev["parent_trace_id"] == chain_trace_id + assert ev["tokens"] == 12 + + +def test_on_llm_without_run_id_is_silent_no_op(): + """ + Some LangChain builds may not forward ``run_id`` to LLM callbacks. + The SDK must not crash and must not invent a span hierarchy — it + falls back to the legacy behaviour of letting ``runtime.track`` + generate a fresh ``trace_id`` (pre-fix behaviour preserved on this + rare path). + """ + cb, spans, llms = _make_cb_with_recorder() + # NOTE: no run_id / parent_run_id kwargs — simulate old LangChain. + cb.on_llm_start(serialized={"id": ["chat"]}, prompts=["hi"]) + cb.on_llm_end( + SimpleNamespace(usage_metadata={"total_tokens": 1}), + invocation_params={"model_name": "gpt-4o"}, + ) + assert spans == [], "no span should be opened when run_id is absent" + assert len(llms) == 1 + # Legacy: trace_id is empty / backend-generated. Pre-fix behaviour. + # We just assert it's a string or None — backend will assign one. + assert llms[0]["type"] == "llm_call" + + +def test_on_llm_end_emits_span_end_even_if_track_raises(): + """ + A failed ``runtime.track`` must not skip the ``span_end`` + emission — otherwise the dashboard leaves dangling spans. + """ + runtime = MagicMock() + spans: list = [] + + def _boom(_): + raise RuntimeError("backend down") + + runtime.track.side_effect = _boom + runtime.track_event.side_effect = lambda **kw: spans.append(kw) + cb = NullRunCallback(runtime=runtime) + cb.on_llm_start(serialized={"id": ["chat"]}, prompts=["hi"], run_id="llm-1") + cb.on_llm_end( + SimpleNamespace(usage_metadata={"total_tokens": 1}), + run_id="llm-1", + invocation_params={"model_name": "gpt-4o"}, + ) + ends = [s for s in spans if s.get("event_type") == "span_end"] + assert len(ends) == 1, "span_end must fire even when track() raises" + + # ─── _active_runs FIFO cap ───────────────────────────────────────────