Skip to content

Commit bfb5838

Browse files
observability: PR #19 round-5 review followups
Two Copilot findings addressed: - **Log-bridge filter on the root logger** — ``install_log_bridge`` was attaching ``_CorrelationIdFilter`` to the OTel ``LoggingHandler`` only. Pre-existing stdout / file / third-party handlers registered ahead of it on the root logger would see log records WITHOUT ``openarmature.correlation_id``, violating spec §7's "every log record emitted during an invocation MUST carry the attribute." Moved the filter to ``root.addFilter(...)`` so it runs at the LOGGER level, applying to every record regardless of which handler processes it. Idempotency is now tracked separately for handler vs filter installation. - **Typed LLM event payload** — ``_make_llm_event`` previously stuffed a plain dict into ``NodeEvent.pre_state`` with ``cast("Any", ...)``, violating the documented ``pre_state: State`` contract. Any observer calling ``event.pre_state.model_dump()`` on an LLM event would crash. Wrapped the payload in a dedicated ``_LlmEventState(State)`` Pydantic subclass with the LLM fields (model, finish_reason, prompt/completion/total tokens, optional error_type / message / category). The OTel observer reads attributes directly via ``isinstance(event.pre_state, _LlmEventState)`` and attribute access. Schema is honored.
1 parent b060790 commit bfb5838

4 files changed

Lines changed: 117 additions & 75 deletions

File tree

src/openarmature/llm/providers/openai.py

Lines changed: 49 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,7 @@
4545
from pydantic import ValidationError
4646

4747
from openarmature.graph.events import NodeEvent
48+
from openarmature.graph.state import State
4849
from openarmature.observability.correlation import current_dispatch
4950

5051
from ..errors import (
@@ -524,6 +525,36 @@ def _looks_like_model_not_loaded(message: object) -> bool:
524525
# ---------------------------------------------------------------------------
525526

526527

528+
class _LlmEventState(State):
529+
"""Typed payload for LLM-provider span events. Subclasses
530+
:class:`openarmature.graph.state.State` so the
531+
``NodeEvent.pre_state: State`` contract holds — observers
532+
calling ``event.pre_state.model_dump()`` (or any other
533+
Pydantic-on-State method) work without the raw-dict overload
534+
that previously violated the schema.
535+
536+
Backend mappings (the OTel observer in this repo, future
537+
Langfuse / Datadog adapters) recognize the
538+
``("openarmature.llm.complete",)`` namespace sentinel and read
539+
these fields directly via attribute access.
540+
"""
541+
542+
model: str
543+
finish_reason: str | None = None
544+
prompt_tokens: int | None = None
545+
completion_tokens: int | None = None
546+
total_tokens: int | None = None
547+
# On error responses the provider caller doesn't have a
548+
# graph-engine §4 ``RuntimeGraphError`` to put in
549+
# ``NodeEvent.error``, so we surface the failure detail through
550+
# these fields instead. ``error_category`` is the canonical §7
551+
# llm-provider category (``provider_unavailable``, etc.) when
552+
# the failed exception carries one.
553+
error_type: str | None = None
554+
error_message: str | None = None
555+
error_category: str | None = None
556+
557+
527558
def _make_llm_event(
528559
phase: Literal["started", "completed"],
529560
*,
@@ -537,40 +568,33 @@ def _make_llm_event(
537568
sentinel ``node_name`` and ``namespace`` and emits an LLM-specific
538569
span instead of a node span. Backend-specific attribute extraction
539570
reads ``model``, ``finish_reason``, and ``usage`` from
540-
``pre_state``'s ``llm_event`` payload.
541-
542-
The pre_state field is reused as the carrier for LLM event detail
543-
because NodeEvent's shape is fixed (graph-engine §6) and adding
544-
ad-hoc fields would break observers that pattern-match on the
545-
existing shape. Backend mappings know to inspect
546-
``event.pre_state['llm_event']`` when the namespace is
547-
``("openarmature.llm.complete",)``.
571+
``pre_state`` directly via attribute access.
548572
"""
549-
payload: dict[str, Any] = {"model": model}
550-
if finish_reason is not None:
551-
payload["finish_reason"] = finish_reason
552-
if usage is not None:
553-
payload["prompt_tokens"] = usage.prompt_tokens
554-
payload["completion_tokens"] = usage.completion_tokens
555-
payload["total_tokens"] = usage.total_tokens
573+
error_type: str | None = None
574+
error_message: str | None = None
575+
error_category: str | None = None
556576
if error is not None:
557-
# The engine's NodeEvent.error type is RuntimeGraphError, but
558-
# llm-provider errors aren't graph-engine §4 categories. Carry
559-
# the exception detail in the payload instead so backends can
560-
# surface it without our needing to wrap as RuntimeGraphError.
561-
payload["error_type"] = type(error).__name__
562-
payload["error_message"] = str(error)
577+
error_type = type(error).__name__
578+
error_message = str(error)
563579
category = getattr(error, "category", None)
564580
if isinstance(category, str):
565-
payload["error_category"] = category
581+
error_category = category
582+
payload = _LlmEventState(
583+
model=model,
584+
finish_reason=finish_reason,
585+
prompt_tokens=usage.prompt_tokens if usage is not None else None,
586+
completion_tokens=usage.completion_tokens if usage is not None else None,
587+
total_tokens=usage.total_tokens if usage is not None else None,
588+
error_type=error_type,
589+
error_message=error_message,
590+
error_category=error_category,
591+
)
566592
return NodeEvent(
567593
node_name="openarmature.llm.complete",
568594
namespace=("openarmature.llm.complete",),
569595
step=-1,
570596
phase=phase,
571-
# ``pre_state`` is overloaded here as the LLM-event payload
572-
# carrier — see the docstring above.
573-
pre_state=cast("Any", {"llm_event": payload}),
597+
pre_state=payload,
574598
post_state=None,
575599
error=None,
576600
parent_states=(),

src/openarmature/observability/otel/logs.py

Lines changed: 36 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -47,13 +47,25 @@ def install_log_bridge(
4747
) -> None:
4848
"""Wire the stdlib root logger to the supplied OTel
4949
:class:`LoggerProvider`. Adds a
50-
:class:`opentelemetry.sdk._logs.LoggingHandler` and an
51-
:class:`_CorrelationIdFilter` so every log record emitted from
52-
anywhere within an invocation carries the active
53-
``trace_id``/``span_id`` + ``openarmature.correlation_id``.
54-
55-
Idempotent: re-calling with a previously-installed provider is
56-
a no-op (we check for an existing OA handler before adding).
50+
:class:`opentelemetry.sdk._logs.LoggingHandler` for OTel-native
51+
``trace_id`` / ``span_id`` bridging, AND attaches an
52+
:class:`_CorrelationIdFilter` directly to the ROOT LOGGER (not
53+
the handler) so the ``openarmature.correlation_id`` attribute
54+
lands on every log record emitted during an invocation —
55+
including records consumed by pre-existing stdout / file /
56+
third-party handlers the user already had configured.
57+
58+
Filter-on-the-root-logger placement matters per spec §7:
59+
"log records emitted from anywhere within an invocation MUST
60+
carry ``openarmature.correlation_id``." A handler-level filter
61+
would only modify records flowing through THAT handler, so a
62+
user's existing stdout handler would see records without the
63+
attribute. The root-logger filter applies to every record,
64+
regardless of which handler eventually processes it.
65+
66+
Idempotent: re-calling is a no-op (we check for the existing
67+
OA-tagged handler AND for an existing filter instance on the
68+
root logger).
5769
5870
The user retains responsibility for providing the
5971
:class:`LoggerProvider` (typically built with their preferred
@@ -63,17 +75,23 @@ def install_log_bridge(
6375
from opentelemetry.sdk._logs import LoggingHandler # type: ignore[attr-defined]
6476

6577
root = logging.getLogger()
66-
# Idempotency check — don't double-install on repeated calls.
67-
for handler in root.handlers:
68-
if isinstance(handler, LoggingHandler) and getattr(handler, "_openarmature_installed", False):
69-
return
70-
handler = LoggingHandler(level=level, logger_provider=provider)
71-
# Direct assignment isn't typed on LoggingHandler; route through
72-
# ``setattr`` to avoid pyright's strict attribute-access check
73-
# without losing the idempotency-marker behavior.
74-
object.__setattr__(handler, "_openarmature_installed", True)
75-
handler.addFilter(_CorrelationIdFilter())
76-
root.addHandler(handler)
78+
# Idempotency #1: don't double-add the OTel LoggingHandler.
79+
handler_already_installed = any(
80+
isinstance(h, LoggingHandler) and getattr(h, "_openarmature_installed", False) for h in root.handlers
81+
)
82+
if not handler_already_installed:
83+
handler = LoggingHandler(level=level, logger_provider=provider)
84+
# Direct assignment isn't typed on LoggingHandler; route
85+
# through ``object.__setattr__`` to avoid pyright's strict
86+
# attribute-access check without losing the idempotency-
87+
# marker behavior.
88+
object.__setattr__(handler, "_openarmature_installed", True)
89+
root.addHandler(handler)
90+
# Idempotency #2: don't double-add the correlation_id filter to
91+
# the root logger.
92+
filter_already_installed = any(isinstance(f, _CorrelationIdFilter) for f in root.filters)
93+
if not filter_already_installed:
94+
root.addFilter(_CorrelationIdFilter())
7795

7896

7997
__all__ = [

src/openarmature/observability/otel/observer.py

Lines changed: 28 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -341,17 +341,24 @@ def _emit_checkpoint_save_span(self, event: NodeEvent) -> None:
341341
def _handle_llm_event(self, event: NodeEvent) -> None:
342342
"""LLM provider span per spec §5.5 — parented to the node
343343
span that invoked the provider."""
344-
# The LLM provider's pre_state carries the event payload
345-
# (model, finish_reason, usage, error detail) since
346-
# NodeEvent's shape is fixed. See
347-
# ``openarmature.llm.providers.openai._make_llm_event``.
348-
payload = cast(
349-
"dict[str, Any]",
350-
cast("dict[str, Any]", event.pre_state).get("llm_event", {}),
351-
)
344+
# ``pre_state`` is a typed ``_LlmEventState`` Pydantic
345+
# subclass — see
346+
# ``openarmature.llm.providers.openai._LlmEventState``. We
347+
# read attributes directly rather than treating the State
348+
# as a dict, preserving the ``NodeEvent.pre_state: State``
349+
# contract for any other observers that consume the event.
350+
# Lazy import to avoid the otel→llm package dependency at
351+
# module load time.
352+
from openarmature.llm.providers.openai import _LlmEventState
353+
354+
if not isinstance(event.pre_state, _LlmEventState):
355+
# Defensive — callers other than the OpenAIProvider hook
356+
# shouldn't dispatch through the LLM_NAMESPACE sentinel.
357+
return
358+
payload = event.pre_state
352359
if event.phase == "started":
353360
parent_ctx = self._current_span_context()
354-
attrs: dict[str, Any] = {"openarmature.llm.model": payload["model"]}
361+
attrs: dict[str, Any] = {"openarmature.llm.model": payload.model}
355362
from openarmature.observability.correlation import current_correlation_id
356363

357364
cid = current_correlation_id()
@@ -370,27 +377,23 @@ def _handle_llm_event(self, event: NodeEvent) -> None:
370377
if open_span is None:
371378
return
372379
span = open_span.span
373-
if "finish_reason" in payload:
374-
span.set_attribute("openarmature.llm.finish_reason", payload["finish_reason"])
375-
for usage_field in (
376-
"prompt_tokens",
377-
"completion_tokens",
378-
"total_tokens",
379-
):
380-
if payload.get(usage_field) is not None:
381-
span.set_attribute(
382-
f"openarmature.llm.usage.{usage_field}",
383-
payload[usage_field],
384-
)
385-
if "error_type" in payload:
380+
if payload.finish_reason is not None:
381+
span.set_attribute("openarmature.llm.finish_reason", payload.finish_reason)
382+
if payload.prompt_tokens is not None:
383+
span.set_attribute("openarmature.llm.usage.prompt_tokens", payload.prompt_tokens)
384+
if payload.completion_tokens is not None:
385+
span.set_attribute("openarmature.llm.usage.completion_tokens", payload.completion_tokens)
386+
if payload.total_tokens is not None:
387+
span.set_attribute("openarmature.llm.usage.total_tokens", payload.total_tokens)
388+
if payload.error_type is not None:
386389
span.set_status(
387390
Status(
388391
StatusCode.ERROR,
389-
description=payload.get("error_category", payload["error_type"]),
392+
description=payload.error_category or payload.error_type,
390393
)
391394
)
392-
if "error_category" in payload:
393-
span.set_attribute("openarmature.error.category", payload["error_category"])
395+
if payload.error_category is not None:
396+
span.set_attribute("openarmature.error.category", payload.error_category)
394397
else:
395398
span.set_status(Status(StatusCode.OK))
396399
span.end()

tests/unit/test_observability_otel.py

Lines changed: 4 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -262,6 +262,8 @@ async def test_disable_llm_spans_skips_llm_provider_span() -> None:
262262
# LLM event through the observer's __call__ and assert no span was
263263
# produced. This isolates the disable_llm_spans branch from the
264264
# provider's own queue-dispatch wiring.
265+
from openarmature.llm.providers.openai import _LlmEventState
266+
265267
exporter = InMemorySpanExporter()
266268
observer = OTelObserver(
267269
span_processor=SimpleSpanProcessor(exporter),
@@ -272,7 +274,7 @@ async def test_disable_llm_spans_skips_llm_provider_span() -> None:
272274
namespace=("openarmature.llm.complete",),
273275
step=-1,
274276
phase="started",
275-
pre_state={"llm_event": {"model": "test-m"}}, # type: ignore[arg-type]
277+
pre_state=_LlmEventState(model="test-m"),
276278
post_state=None,
277279
error=None,
278280
parent_states=(),
@@ -282,12 +284,7 @@ async def test_disable_llm_spans_skips_llm_provider_span() -> None:
282284
namespace=("openarmature.llm.complete",),
283285
step=-1,
284286
phase="completed",
285-
pre_state={ # type: ignore[arg-type]
286-
"llm_event": {
287-
"model": "test-m",
288-
"finish_reason": "stop",
289-
}
290-
},
287+
pre_state=_LlmEventState(model="test-m", finish_reason="stop"),
291288
post_state=None,
292289
error=None,
293290
parent_states=(),

0 commit comments

Comments
 (0)