Skip to content

Commit 2df68a1

Browse files
authored
fix: 0.8.3 — close silent zero-billing across langgraph + init-ordering (#42)
* fix: 0.8.3 — close silent zero-billing across langgraph + init-ordering Three coordinated defenses against the same class of bug the 0.8.2 audit closed on the httpx path: llm_call events reaching the backend without a model field were silently recorded as ≈$0 (backend unwrap_or('default') + DEFAULT_RATE). 0.8.3 closes the langgraph callback path and the init-ordering hazard, and promotes the missing-model wire failure from WARN to fail-LOUD. 1. langgraph callback path (instrumentation/langgraph.py) _extract_model_from_response now consults response.llm_output FIRST — that's where langchain-openai 1.x puts the date-suffixed model id (e.g. 'gpt-4.1-mini-2025-04-14'). The previous chain led with response_metadata, which langchain 1.x leaves empty on the AIMessage inside generations[0][0].message. Without this promotion every OpenAI-via-LangChain 1.x call silently zero-billed. Also adds a 'any key containing model' sweep inside llm_output so non-OpenAI wrappers (proxies, custom chat models) still get attributed. 2. Init-ordering hazard (instrumentation/auto.py) patch_httpx's class-level __init__ wrap only catches Clients created AFTER it is installed. Users that build ChatOpenAI(...) before nullrun.init(api_key=...) get a pre-existing httpx.Client that the patch never sees — those clients keep the unpatched transport and emit nothing. We now sweep gc.get_objects() once at patch install time and wrap any pre-existing Client/AsyncClient whose transport isn't already a NullRun*Transport. Idempotent via the existing class-level marker. 3. Fail-LOUD wire tag (runtime.py) runtime.track() now escalates the missing-model warning from logger.warning to logger.error, bumps a runtime counter (dropped_llm_call_no_model) for dashboards, and tags the wire event with __missing_model: True so the backend's into_track_request gate can reject with HTTP 422 instead of silently recording a zero-cost call. The event is still sent (not fail-CLOSED) so the backend can audit the rejection; the flag is wire-private and stripped before persisting. tests/contract/test_llm_call_model_wire.py pins all three invariants: 7 unit tests for _extract_model_from_response (every known langchain shape + non-OpenAI wrappers + empty-string fallthrough), 3 tests for track()'s missing-model wire tagging (ERROR + counter + __missing_model flag + non-llm_call silence), and 2 tests for the eager-wrap sweep (pre-existing Client gets wrapped, idempotent on re-patch). * style(auto): sort stdlib imports (ruff I001) `import gc` was inserted between `hashlib` and `json`; ruff's isort rule wants `gc` before `hashlib` alphabetically.
1 parent d4884a7 commit 2df68a1

5 files changed

Lines changed: 508 additions & 31 deletions

File tree

src/nullrun/instrumentation/auto.py

Lines changed: 84 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@
3535

3636
from __future__ import annotations
3737

38+
import gc
3839
import hashlib
3940
import json
4041
import logging
@@ -1038,9 +1039,92 @@ def _wrap_async_init(self: httpx.AsyncClient, *args: Any, **kwargs: Any) -> None
10381039
httpx.AsyncClient._nullrun_patched = True # type: ignore[attr-defined]
10391040
_httpx_patched = True
10401041
logger.info("httpx auto-instrumentation installed (sync + async)")
1042+
1043+
# Audit 2026-06-29 (init-ordering hazard): the class-level
1044+
# __init__ patch only wraps httpx.Clients created AFTER it is
1045+
# installed. If a user does
1046+
#
1047+
# llm = ChatOpenAI(model="gpt-4.1-mini") # before init()
1048+
# nullrun.init(api_key=...) # patch installed here
1049+
#
1050+
# ``ChatOpenAI`` already built its internal httpx.Client (or
1051+
# will on first .invoke()), but that client is reachable from
1052+
# the running process right now and is using the unpatched
1053+
# transport. Without the eager sweep below, the httpx path
1054+
# emits nothing for that LLM — every call silently zero-billed
1055+
# via the langchain callback fallback (or the bare-LLMResult
1056+
# path with no model).
1057+
#
1058+
# We sweep gc.get_objects() once and wrap any pre-existing
1059+
# httpx.Client/AsyncClient whose transport isn't already a
1060+
# NullRun*Transport. The class-level marker on ``__init__`` is
1061+
# set, so future constructions auto-wrap — this sweep is the
1062+
# back-fill for the instances that pre-date the patch.
1063+
try:
1064+
sync_wrapped, async_wrapped = _wrap_pre_existing_httpx_clients(runtime)
1065+
if sync_wrapped or async_wrapped:
1066+
logger.info(
1067+
"httpx eager wrap: %d sync + %d async pre-existing "
1068+
"client(s) now route through NullRun",
1069+
sync_wrapped,
1070+
async_wrapped,
1071+
)
1072+
except Exception as exc: # noqa: BLE001 — defensive, never block init
1073+
logger.debug("httpx eager wrap sweep failed: %s", exc)
10411074
return True
10421075

10431076

1077+
def _wrap_pre_existing_httpx_clients(runtime: Any) -> tuple[int, int]:
1078+
"""Find httpx clients created before ``patch_httpx`` ran and wrap their
1079+
transports in NullRun's transports.
1080+
1081+
Audit 2026-06-29 (init-ordering hazard): the typical sequence
1082+
1083+
llm = ChatOpenAI(model=...) # builds internal httpx.Client
1084+
nullrun.init(api_key=...) # installs the __init__ patch
1085+
1086+
leaves ``llm``'s internal client with the unpatched transport.
1087+
New ``httpx.Client()`` constructions are auto-wrapped by the
1088+
class-level patch; this sweep is the back-fill.
1089+
1090+
Returns ``(sync_count, async_count)`` for logging. Errors are
1091+
swallowed by the caller — this is a best-effort back-fill, never
1092+
a hard requirement.
1093+
1094+
We use ``gc.get_objects()`` because httpx does not maintain a
1095+
weakref registry of its Client instances. The sweep is O(heap);
1096+
on a typical agent process (hundreds of MB heap, mostly strings
1097+
and small dicts) this takes <50 ms. We bail early on
1098+
``RuntimeError`` (raised by ``gc.get_objects()`` when the
1099+
interpreter is shutting down) and on any ``isinstance`` failure
1100+
(a class with a broken ``__class__``).
1101+
"""
1102+
sync_count = 0
1103+
async_count = 0
1104+
try:
1105+
for obj in gc.get_objects():
1106+
try:
1107+
if isinstance(obj, httpx.Client) and not isinstance(
1108+
obj._transport, NullRunSyncTransport
1109+
):
1110+
obj._transport = NullRunSyncTransport(obj._transport, runtime)
1111+
sync_count += 1
1112+
elif isinstance(obj, httpx.AsyncClient) and not isinstance(
1113+
obj._transport, NullRunAsyncTransport
1114+
):
1115+
obj._transport = NullRunAsyncTransport(obj._transport, runtime)
1116+
async_count += 1
1117+
except (ReferenceError, TypeError, AttributeError):
1118+
# gc.get_objects can yield objects that are mid-GC or
1119+
# have a broken __class__; skip them rather than abort.
1120+
continue
1121+
except RuntimeError:
1122+
# gc.get_objects() raises RuntimeError during interpreter
1123+
# shutdown. Nothing to do.
1124+
pass
1125+
return sync_count, async_count
1126+
1127+
10441128
# ---------------------------------------------------------------------------
10451129
# D4: patch_langchain_callback — in-memory mocks + callback-only flows
10461130
# ---------------------------------------------------------------------------

src/nullrun/instrumentation/langgraph.py

Lines changed: 75 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -718,26 +718,77 @@ def _extract_model_from_response(response: Any) -> str | None:
718718
Returns the first non-empty value found, or ``None`` if every known
719719
source is empty / malformed.
720720
721+
Audit 2026-06-29 (SDK↔backend wire: silent zero-billing): the chain
722+
was checked top-to-bottom and silently returned ``None`` whenever
723+
none of the four known locations carried the model. The backend
724+
then ``unwrap_or("default")``'d to ``DEFAULT_RATE`` and every call
725+
was recorded as ≈$0. We now:
726+
727+
- promote ``response.llm_output['model_name']`` (the location
728+
langchain-openai 1.x uses for the date-suffixed model id
729+
``gpt-4.1-mini-2025-04-14``) to step 1, ahead of the
730+
``response_metadata`` step that langchain 0.x used;
731+
- add ``response.llm_output['model']`` and a generic
732+
"any key containing 'model'" sweep so non-OpenAI wrappers
733+
(proxies, custom chat models) still get attributed;
734+
- log a DEBUG line on the None path so an operator who sees
735+
the wire warning in the backend can correlate it to the
736+
observation site that produced the event.
737+
721738
Sources checked, in order:
722739
723-
1. ``response.response_metadata['model_name']`` — OpenAI-via-LangChain
724-
puts the real model id (e.g. ``"gpt-4.1-mini-2025-04-14"``) here.
725-
2. ``response.generations[0][0].message.response_metadata['model_name']``
726-
— LLMResult callback path where the metadata lives on the AIMessage
727-
rather than the LLMResult itself.
728-
3. ``response.llm_output['model_name']`` — legacy LLMResult where the
729-
chat-model wrapper hoisted the field onto the LLMResult dict.
730-
4. ``response.model`` / ``response.model_name`` — direct attributes
731-
on the response object (rare but seen in some custom wrappers).
740+
1. ``response.llm_output['model_name']`` / ``['model']`` /
741+
any key containing "model" — langchain-openai 1.x puts the
742+
date-suffixed id (e.g. ``"gpt-4.1-mini-2025-04-14"``) on
743+
``LLMResult.llm_output``. The backend's ``MODEL_RATES``
744+
substring-match handles the date suffix.
745+
2. ``response.response_metadata['model_name']`` — direct AIMessage
746+
case (langchain 0.x chat-model wrappers expose metadata at
747+
this level).
748+
3. ``response.generations[0][0].message.response_metadata['model_name']``
749+
— LLMResult callback path where the metadata lives on the
750+
AIMessage rather than the LLMResult itself.
751+
4. Direct ``response.model`` / ``response.model_name`` attributes
752+
(rare, seen on some custom wrappers).
732753
"""
733-
# 1. response_metadata on the response.
754+
# 1. llm_output dict (langchain-openai 1.x primary location).
755+
# Promote ahead of the response_metadata step: for OpenAI via
756+
# LangChain 1.x, the LLMResult carries the model on
757+
# ``llm_output['model_name']`` (date-suffixed) while the
758+
# AIMessage inside ``generations[0][0].message`` does NOT
759+
# carry ``response_metadata`` populated — step 3 would return
760+
# None. Without promoting step 1, every OpenAI call was
761+
# silently zero-billed.
762+
llm_out = getattr(response, "llm_output", None)
763+
if isinstance(llm_out, dict) and llm_out:
764+
# Preferred: explicit "model_name" then "model" key.
765+
for key in ("model_name", "model"):
766+
val = llm_out.get(key)
767+
if isinstance(val, str) and val:
768+
return val
769+
# Fallback: scan every key in llm_output for one that
770+
# contains "model" and holds a non-empty string. Some
771+
# custom chat-model wrappers / proxies put the model under
772+
# less canonical keys (``"model_id"``, ``"modelName"``,
773+
# ``"resolved_model"``).
774+
for key, val in llm_out.items():
775+
if (
776+
isinstance(key, str)
777+
and "model" in key.lower()
778+
and isinstance(val, str)
779+
and val
780+
):
781+
return val
782+
783+
# 2. response_metadata on the response (langchain 0.x AIMessage
784+
# case, and any wrapper that hoists the metadata up).
734785
resp_meta = getattr(response, "response_metadata", None)
735786
if isinstance(resp_meta, dict):
736787
val = resp_meta.get("model_name") or resp_meta.get("model")
737788
if val:
738789
return str(val)
739790

740-
# 2. LLMResult callback path — look on the generation's AIMessage.
791+
# 3. LLMResult callback path — look on the generation's AIMessage.
741792
gen_msg = _safe_get_gen_message(response)
742793
if gen_msg is not None:
743794
gm = getattr(gen_msg, "response_metadata", None)
@@ -751,19 +802,25 @@ def _extract_model_from_response(response: Any) -> str | None:
751802
if v:
752803
return str(v)
753804

754-
# 3. llm_output dict (legacy LLMResult).
755-
llm_out = getattr(response, "llm_output", None)
756-
if isinstance(llm_out, dict):
757-
val = llm_out.get("model_name") or llm_out.get("model")
758-
if val:
759-
return str(val)
760-
761805
# 4. Direct attribute on response.
762806
for attr in ("model_name", "model"):
763807
v = getattr(response, attr, None)
764808
if v:
765809
return str(v)
766810

811+
# Diagnostic: every code path above returned None. The runtime
812+
# layer will warn at ERROR when this happens for an llm_call
813+
# event; this DEBUG line is for the per-call site so the
814+
# operator can correlate the wire warning back to a specific
815+
# response shape.
816+
try:
817+
response_type = type(response).__name__
818+
except Exception:
819+
response_type = "<unknown>"
820+
logger.debug(
821+
"_extract_model_from_response returned None for response of type %s",
822+
response_type,
823+
)
767824
return None
768825

769826

src/nullrun/runtime.py

Lines changed: 28 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1430,23 +1430,38 @@ def track(
14301430
if k not in _WIRE_STRIP_FIELDS and v is not None
14311431
}
14321432

1433-
# Audit 2026-06-28 (SDK↔backend wire): backend cost pipeline
1434-
# emits ``WARN model_id=default`` whenever an llm_call event
1435-
# reaches the wire without a ``model`` field
1436-
# (pipeline.rs:164 ``unwrap_or("default")``). This log lets
1437-
# operators reproduce the path: which observation (httpx /
1438-
# langchain callback / manual track / agents tracer / requests)
1439-
# produced an llm_call without ``model`` set, and whether
1440-
# the SDK explicitly passed ``model=None``, omitted the key,
1441-
# or had ``model=""`` (which the ``if model:`` guard in
1442-
# track_llm silently drops). Activated only for llm_call so
1443-
# span_start/span_end/tool_call traffic doesn't pollute logs.
1433+
# Audit 2026-06-29 (SDK↔backend wire: silent zero-billing):
1434+
# backend cost pipeline emits ``WARN model_id=default``
1435+
# whenever an llm_call event reaches the wire without a
1436+
# ``model`` field (pipeline.rs:176 ``unwrap_or("default")``).
1437+
# Pre-fix the SDK warned and continued — the backend then
1438+
# silently fell through to ``DEFAULT_RATE`` and every call
1439+
# was recorded as ≈$0, breaking budget enforcement.
1440+
#
1441+
# Post-fix the SDK is fail-LOUD (not fail-closed yet — the
1442+
# event is still sent so the backend can audit/reject):
1443+
#
1444+
# 1. ERROR log instead of WARN — operator sees the breakage
1445+
# immediately, not buried in routine log noise.
1446+
# 2. Bump the ``dropped_llm_call_no_model`` runtime counter
1447+
# so dashboards can surface the regression rate.
1448+
# 3. Tag the wire event with ``__missing_model: True`` so
1449+
# the backend's into_track_request gate (fail-CLOSED
1450+
# layer) can reject with HTTP 422 and a clear error
1451+
# envelope instead of silently recording a zero-cost
1452+
# call. The flag is treated as a wire-private signal —
1453+
# the backend strips it before persisting.
1454+
#
1455+
# Activated only for llm_call so span_start/span_end/
1456+
# tool_call traffic doesn't pollute logs or the wire.
14441457
if wire_event.get("type") == "llm_call" and not wire_event.get("model"):
1445-
logger.warning(
1458+
logger.error(
14461459
"track(): llm_call event missing 'model' field — "
1447-
"backend will fall back to DEFAULT_RATE. event=%s",
1460+
"tagging for backend rejection (HTTP 422). event=%s",
14481461
wire_event,
14491462
)
1463+
metrics.inc_runtime("dropped_llm_call_no_model")
1464+
wire_event["__missing_model"] = True
14501465

14511466
self._transport.track(wire_event)
14521467

tests/contract/__init__.py

Whitespace-only changes.

0 commit comments

Comments
 (0)