From 602347d76c4e5e464e883f5df32b5bad5aa7952b Mon Sep 17 00:00:00 2001 From: Aakash Kattelu Date: Thu, 2 Jul 2026 13:49:53 -0700 Subject: [PATCH] feat(telemetry): CloudEvents + Langfuse tracing as projections over a captured LLM stream (#845) * feat(telemetry): CloudEvents + Langfuse tracing as projections over a captured LLM stream Capture each LLM call once (CapturedLLMCall) and fan it out to multiple exporters -- "one data model, two projections": a CloudEvents trace stream (llm.call.traced / trace.content) and a Langfuse projection, both reconstructing trace -> run -> step -> generation from the same source of truth. - Capture seam (src/llm/capture.py): one canonicalization + content-addressed hashing point, with an O(N) per-span memo so repeated context isn't re-hashed. - Session correlation threaded telemetry -> captured call -> exporters, namespaced only at the Langfuse export boundary. - Span identity consolidated onto LLMTelemetryContext; dropped TRACE_ENDPOINT. - Canonical generation/step names; dreamer branches nest under one dream trace; tool calls become spans under their step. - LANGFUSE_EXPORTER_MODE toggle ("exporter" default; "inline" kept one release for side-by-side validation), centralized into computed settings predicates. - Per-run/per-trace dedup registries (trace_session, langfuse_session) bounded by an LRU so dedup and span grouping survive long-running workers. - Embedding-call tracing; deterministic high-volume event sampling. Co-Authored-By: Claude Opus 4.8 * fix(telemetry): address trace-review findings (span/step_seq collisions, test, logging) - Dreamer specialists mint a distinct span_id per execution (trace_id stays the shared dream run_id), so their CloudEvents trace resource ids no longer collide between deduction and induction. - Tool-loop no-tool early-return streams the tail with the next ordinal (iteration+2) instead of reusing the in-loop call's step_seq, avoiding a colliding trace resource id; mirrors the synthesis path. - Tighten test_clips_oversized_string to assert output stays within TRACE_MAX_BYTES. - emit_trace logs the swallowed exception with exc_info for debuggability. Co-Authored-By: Claude Opus 4.8 * fix(telemetry): silence exporter-mode Langfuse warning + drop summarizer run_id placeholder Two CloudEvents/Langfuse correctness fixes, independent of the trace viewer. Langfuse exporter-mode gating: annotate_current_generation_io (and its two executor.py call-site guards) were gated on LANGFUSE_PUBLIC_KEY instead of langfuse_inline_enabled. In the default `exporter` mode they called get_client().update_current_generation() with no active @observe span, logging "No active span in current context" (~14 per dialectic run) and building throwaway model_dump payloads on every LLM call. The LangfuseExporter projects I/O from the captured stream, so these helpers must no-op in exporter mode. Gated all three on langfuse_inline_enabled; added a regression test; fixed a stale conditional_observe docstring. Summarizer run_id placeholder: AgentToolSummaryCreatedEvent hardcoded run_id="deriver"/iteration=0 because summarization is a single LLM call, not an agentic run. That placeholder pollutes run_id grouping in the CloudEvents stream (any consumer that groups by run_id sees a phantom "deriver" run). Made run_id/iteration optional (None) and re-keyed get_resource_id on message_id:summary_type (the real per-summary identity; run_id/iteration can no longer identify it); bumped schema_version 2->3. Xatu ingestion stores only the CloudEvent envelope, so the field/resource_id/version changes are transparent to it. Co-Authored-By: Claude Opus 4.8 * docs: update docstrings to be less verbose * fix(telemetry): address PR review on captured-stream tracing - embedding traces get a fresh span_id under parent_span_id=run_id, so sibling embeddings in one run no longer share a span/idempotency key - capture the provider finish_reason from stream chunks instead of hardcoding "stop" on a successful drain - gate the Langfuse exporter behind TELEMETRY.ENABLED (master switch) so disabling telemetry sends no traces at all - rename _emit_derived_content -> _emit_hashed_content - inline the _emit_trace wrapper; drop unused trace_session.end_run Co-Authored-By: Claude Opus 4.8 (1M context) * refactor: rename TELEMETRY_TRACE_PAYLOADS to TELEMETRY_TRACE_PAYLOADS_ENABLED * fix(telemetry): capture provider tool calls in trace stream The captured trace stream dropped assistant tool calls for openai/gemini: build_captured_messages only read {role, content, tool_call_id}, but those providers keep tool calls outside content (openai's tool_calls, gemini's parts), so replayed tool-call turns landed as empty content and gemini lost its text and tool results entirely. Anthropic (tool_use in content) was fine. Normalize each input message per provider into a unified tool_calls [{id, name, input}] field on CapturedMessage/TraceContentEvent, recovering gemini text/results along the way, and fold tool_calls into compute_content_hash so empty-content openai turns no longer collide in the dedup store. langfuse_exporter._input now surfaces the calls. Also fix a silent serialization drop: gemini thought_signature is bytes, so model_dump(mode="json") on the traced event raised UnicodeDecodeError and emit_trace swallowed it -- dropping the whole tool-calling iteration from the trace stream (billing and Langfuse were unaffected). base64-encode the signature on the telemetry path; replay keeps the raw bytes. Co-Authored-By: Claude Opus 4.8 (1M context) * fix(telemetry): type replay tool-call dict for bytes signature thought_signature widened to str | bytes | None, but _tool_call_result_to_dict's literal was inferred as dict[str, str | dict[str, Any]], so the bytes assignment failed project-wide basedpyright (the per-file pre-commit hook didn't catch it). Annotate the dict as dict[str, Any]; the replay path keeps the raw bytes unchanged. Co-Authored-By: Claude Opus 4.8 (1M context) * test: remove 3 tests --------- Co-authored-by: Claude Opus 4.8 --- .env.template | 5 + src/config.py | 48 ++ src/deriver/deriver.py | 5 + src/dialectic/chat.py | 8 + src/dialectic/core.py | 7 + src/dreamer/specialists.py | 9 + src/embedding_client.py | 26 ++ src/llm/backend.py | 3 +- src/llm/capture.py | 403 ++++++++++++++++ src/llm/executor.py | 73 ++- src/llm/runtime.py | 62 ++- src/llm/tool_loop.py | 109 ++++- src/llm/types.py | 82 +++- src/telemetry/__init__.py | 2 + src/telemetry/emitter.py | 63 ++- src/telemetry/events/__init__.py | 74 ++- src/telemetry/events/agent.py | 19 +- src/telemetry/events/trace.py | 161 +++++++ src/telemetry/langfuse_exporter.py | 398 ++++++++++++++++ src/telemetry/langfuse_session.py | 122 +++++ src/telemetry/logging.py | 11 +- src/telemetry/trace_exporter.py | 169 +++++++ src/telemetry/trace_session.py | 73 +++ src/utils/agent_tools.py | 7 +- src/utils/summarizer.py | 19 +- src/utils/types.py | 17 + tests/llm/test_capture.py | 488 ++++++++++++++++++++ tests/llm/test_langfuse_trace_annotation.py | 123 +++-- tests/llm/test_telemetry_agent_iteration.py | 10 +- tests/telemetry/conftest.py | 36 ++ tests/telemetry/test_cross_agent_trace.py | 215 +++++++++ tests/telemetry/test_embedding_trace.py | 111 +++++ tests/telemetry/test_emit_function.py | 12 +- tests/telemetry/test_events.py | 5 +- tests/telemetry/test_langfuse_exporter.py | 438 ++++++++++++++++++ tests/telemetry/test_trace_events.py | 218 +++++++++ tests/utils/test_clients.py | 2 + 37 files changed, 3519 insertions(+), 114 deletions(-) create mode 100644 src/llm/capture.py create mode 100644 src/telemetry/events/trace.py create mode 100644 src/telemetry/langfuse_exporter.py create mode 100644 src/telemetry/langfuse_session.py create mode 100644 src/telemetry/trace_exporter.py create mode 100644 src/telemetry/trace_session.py create mode 100644 tests/llm/test_capture.py create mode 100644 tests/telemetry/test_cross_agent_trace.py create mode 100644 tests/telemetry/test_embedding_trace.py create mode 100644 tests/telemetry/test_langfuse_exporter.py create mode 100644 tests/telemetry/test_trace_events.py diff --git a/.env.template b/.env.template index ebe7fa16..24014ee2 100644 --- a/.env.template +++ b/.env.template @@ -276,6 +276,11 @@ LLM_OPENAI_API_KEY=your-api-key-here # TELEMETRY_MAX_BUFFER_SIZE=10000 # TELEMETRY_NAMESPACE=honcho # Inherits from NAMESPACE if not set +# Full-fidelity payload tracing (llm.call.traced / trace.content). Default-off +# TELEMETRY_TRACE_PAYLOADS_ENABLED=false # Trace events ship to TELEMETRY_ENDPOINT +# TELEMETRY_TRACE_MAX_BYTES=262144 # Per-message cap; oversized content is clipped +# TELEMETRY_TRACE_PURPOSES=[] # JSON list of CallPurpose values to capture; empty = all + # ============================================================================= # Cache # ============================================================================= diff --git a/src/config.py b/src/config.py index 5a0e3937..0e39fdcc 100644 --- a/src/config.py +++ b/src/config.py @@ -1176,6 +1176,19 @@ class TelemetrySettings(HonchoSettings): # that join high-volume events to aggregate envelopes first. HIGH_VOLUME_SAMPLE_RATE: Annotated[float, Field(default=1.0, ge=0.0, le=1.0)] = 1.0 + # --- Full-fidelity payload tracing (llm.call.traced / trace.content) --- + # Master toggle for replay-grade content capture. Default-off. + TRACE_PAYLOADS_ENABLED: bool = False + + # Per-message cap (bytes) for captured content; oversized string content is + # clipped (with a marker) and the call is flagged was_truncated. + TRACE_MAX_BYTES: Annotated[int, Field(default=262144, gt=0)] = 262144 + + # Allowlist of CallPurpose values to capture; empty = all. Typed as str to + # keep the enum out of config (validated against CallPurpose at the producer, + # same pattern as LLMTelemetryContext.call_purpose). + TRACE_PURPOSES: list[str] = Field(default_factory=list) + class CacheSettings(HonchoSettings): model_config = SettingsConfigDict(env_prefix="CACHE_", extra="ignore") # pyright: ignore @@ -1345,6 +1358,17 @@ class VectorStoreSettings(HonchoSettings): return self +class TraceViewerSettings(HonchoSettings): + model_config = SettingsConfigDict(env_prefix="TRACE_VIEWER_", extra="ignore") # pyright: ignore + + ENABLED: bool = False + HOST: str = "127.0.0.1" + PORT: int = 8002 + STORAGE_DIR: str = "./traces" + MAX_REQUEST_BYTES: int = 10 * 1024 * 1024 # 10 MB + VENDOR_CDN_BASE: str = "https://cdn.jsdelivr.net/npm" + + class AppSettings(HonchoSettings): # No env_prefix for app-level settings model_config = SettingsConfigDict( # pyright: ignore @@ -1364,6 +1388,29 @@ class AppSettings(HonchoSettings): EMBED_MESSAGES: bool = True LANGFUSE_HOST: str | None = None LANGFUSE_PUBLIC_KEY: str | None = None + # How Langfuse traces are produced: + # "exporter" (default) — Langfuse is a projection over the captured + # CapturedLLMCall stream (LangfuseExporter), the same source of truth as + # the CloudEvents trace stream. + # "inline" — legacy live instrumentation (@observe + propagate_attributes + # spans during execution). Kept one release for side-by-side validation. + LANGFUSE_EXPORTER_MODE: Literal["inline", "exporter"] = "exporter" + + @property + def langfuse_inline_enabled(self) -> bool: + """True when the legacy inline Langfuse instrumentation is active + (keys configured + ``LANGFUSE_EXPORTER_MODE == "inline"``).""" + return ( + bool(self.LANGFUSE_PUBLIC_KEY) and self.LANGFUSE_EXPORTER_MODE == "inline" + ) + + @property + def langfuse_exporter_enabled(self) -> bool: + """True when the Langfuse exporter (a projection over the captured call + stream) is active (keys configured + ``LANGFUSE_EXPORTER_MODE == "exporter"``).""" + return ( + bool(self.LANGFUSE_PUBLIC_KEY) and self.LANGFUSE_EXPORTER_MODE == "exporter" + ) # Origins allowed by the FastAPI CORSMiddleware CORS_ORIGINS: list[str] = [ @@ -1394,6 +1441,7 @@ class AppSettings(HonchoSettings): CACHE: CacheSettings = Field(default_factory=CacheSettings) DREAM: DreamSettings = Field(default_factory=DreamSettings) VECTOR_STORE: VectorStoreSettings = Field(default_factory=VectorStoreSettings) + TRACE_VIEWER: TraceViewerSettings = Field(default_factory=TraceViewerSettings) @field_validator("LOG_LEVEL") def validate_log_level(cls, v: str) -> str: diff --git a/src/deriver/deriver.py b/src/deriver/deriver.py index c6c3aa2c..0db9477d 100644 --- a/src/deriver/deriver.py +++ b/src/deriver/deriver.py @@ -1,6 +1,8 @@ import logging import time +from nanoid import generate as generate_nanoid + from src import crud from src.config import ConfiguredModelSettings, settings from src.crud.representation import RepresentationManager @@ -142,6 +144,7 @@ async def process_representation_tasks_batch( model_config = base_model_config # Single LLM call + trace_id = generate_nanoid() llm_start = time.perf_counter() response = await honcho_llm_call( model_config=model_config, @@ -159,6 +162,8 @@ async def process_representation_tasks_batch( parent_category="representation", observed=observed, track_name="Minimal Deriver", + trace_id=trace_id, + span_id=trace_id, ), ) llm_duration = (time.perf_counter() - llm_start) * 1000 diff --git a/src/dialectic/chat.py b/src/dialectic/chat.py index ae6ea290..9c118803 100644 --- a/src/dialectic/chat.py +++ b/src/dialectic/chat.py @@ -50,6 +50,9 @@ async def agentic_chat( session = await crud.get_session( db, workspace_name=workspace_name, session_name=session_name ) + # Read the opaque Session.id while the instance is still bound; the ORM + # object detaches once this read-only session closes below. + session_id = session.id if session else None workspace = await crud.get_workspace(db, workspace_name=workspace_name) configuration = get_configuration(None, session, workspace) @@ -68,6 +71,7 @@ async def agentic_chat( agent = DialecticAgent( workspace_name=workspace_name, session_name=session_name, + session_id=session_id, observer=observer, observed=observed, observer_peer_card=observer_peer_card, @@ -111,6 +115,9 @@ async def agentic_chat_stream( session = await crud.get_session( db, workspace_name=workspace_name, session_name=session_name ) + # Read the opaque Session.id while the instance is still bound; the ORM + # object detaches once this read-only session closes below. + session_id = session.id if session else None workspace = await crud.get_workspace(db, workspace_name=workspace_name) configuration = get_configuration(None, session, workspace) @@ -129,6 +136,7 @@ async def agentic_chat_stream( agent = DialecticAgent( workspace_name=workspace_name, session_name=session_name, + session_id=session_id, observer=observer, observed=observed, observer_peer_card=observer_peer_card, diff --git a/src/dialectic/core.py b/src/dialectic/core.py index 64895cb9..6f5b17ab 100644 --- a/src/dialectic/core.py +++ b/src/dialectic/core.py @@ -68,6 +68,7 @@ class DialecticAgent: observed_peer_card: list[str] | None = None, metric_key: str | None = None, reasoning_level: ReasoningLevel = "low", + session_id: str | None = None, ): """ Initialize the dialectic agent. @@ -81,9 +82,11 @@ class DialecticAgent: observed_peer_card: Biographical information about the observed peer metric_key: Optional key for logging metrics (if provided, agent won't log separately) reasoning_level: Level of reasoning to apply + session_id: ID used for grouping traces (not session_name) """ self.workspace_name: str = workspace_name self.session_name: str | None = session_name + self.session_id: str | None = session_id self.observer: str = observer self.observed: str = observed self.observer_peer_card: list[str] | None = observer_peer_card @@ -179,6 +182,7 @@ class DialecticAgent: workspace_name=self.workspace_name, run_id=self._run_id, parent_category="dialectic", + session_id=self.session_id, ): query_embedding = await embedding_client.embed(query) @@ -316,6 +320,9 @@ class DialecticAgent: parent_category="dialectic", agent_type="dialectic", run_id=self._run_id, + trace_id=self._run_id, + span_id=self._run_id, + session_id=self.session_id, peer_name=self.observed, track_name=track_name, ) diff --git a/src/dreamer/specialists.py b/src/dreamer/specialists.py index c0d86585..b0d44ec8 100644 --- a/src/dreamer/specialists.py +++ b/src/dreamer/specialists.py @@ -169,6 +169,10 @@ If you update it, send the full deduplicated list and remove stale entries. SpecialistResult with metrics and content """ run_id = parent_run_id or generate_nanoid() + # Specialists sharing the orchestrator's run_id (one dream trace) each get a + # distinct span_id so their CloudEvents trace resource ids don't collide; + # trace_id stays run_id so Langfuse still groups them (keyed by agent_type). + span_id = generate_nanoid() if parent_run_id is not None else run_id task_name = f"dreamer_{self.name}_{run_id}" start_time = time.perf_counter() @@ -292,6 +296,11 @@ If you update it, send the full deduplicated list and remove stale entries. parent_category="dream", agent_type=self.name, run_id=run_id, + # Root span per specialist run (distinct span_id, see above). + # parent_span_id stays None for now; wiring specialists as + # children of a dream-level trace is forking (out of scope). + trace_id=run_id, + span_id=span_id, observer=observer, observed=observed, track_name=f"Dreamer/{self.name}", diff --git a/src/embedding_client.py b/src/embedding_client.py index 1efdc3d2..07197f43 100644 --- a/src/embedding_client.py +++ b/src/embedding_client.py @@ -9,6 +9,7 @@ from typing import Any, Literal, NamedTuple, TypeVar import tiktoken from google import genai from google.genai import types as genai_types +from nanoid import generate as generate_nanoid from openai import AsyncOpenAI from .config import EmbeddingModelConfig, resolve_embedding_model_config, settings @@ -88,6 +89,7 @@ def _publish_embedding_event( get_embedding_call_purpose, get_embedding_parent_category, get_embedding_run_id, + get_embedding_session_id, get_embedding_workspace_name, ) @@ -121,6 +123,30 @@ def _publish_embedding_event( run_id=get_embedding_run_id(), ) ) + + # Trace stream (ground-truth) — gated on payload tracing. Each embedding + # gets its own span nested under the driving agent run (parent_span_id = + # run_id), so multiple embeddings in one run don't share a span id. + if settings.TELEMETRY.TRACE_PAYLOADS_ENABLED: + from src.telemetry.events import EmbeddingCallTracedEvent, emit_trace + + run_id = get_embedding_run_id() + span_id = generate_nanoid() + emit_trace( + EmbeddingCallTracedEvent( + trace_id=run_id or span_id, + span_id=span_id, + parent_span_id=run_id, + session_id=get_embedding_session_id(), + call_purpose=purpose_slug, + parent_category=get_embedding_parent_category(), + provider=provider, + model=model, + provider_input_tokens=input_tokens_estimate, + provider_output_tokens=0, + input_count=input_count, + ) + ) except Exception: # pragma: no cover - telemetry must not raise logger.debug("Failed to emit EmbeddingCallCompletedEvent", exc_info=True) diff --git a/src/llm/backend.py b/src/llm/backend.py index 5645998c..380911d2 100644 --- a/src/llm/backend.py +++ b/src/llm/backend.py @@ -14,7 +14,8 @@ class ToolCallResult: id: str name: str input: dict[str, Any] - thought_signature: str | None = None + # Gemini returns this as raw bytes; other providers omit it. + thought_signature: str | bytes | None = None @dataclass(slots=True) diff --git a/src/llm/capture.py b/src/llm/capture.py new file mode 100644 index 00000000..ff0d1b0e --- /dev/null +++ b/src/llm/capture.py @@ -0,0 +1,403 @@ +"""Structures for data captured from LLM calls via telemetry. + +All capture is best-effort: `dispatch_captured_call` swallows exporter exceptions +so telemetry can never break the LLM call path. +""" + +from __future__ import annotations + +import base64 +import contextlib +import hashlib +import json +import logging +from dataclasses import dataclass, field +from typing import Any, Protocol, cast, runtime_checkable + +from src.config import settings + +from .backend import CompletionResult as BackendCompletionResult +from .backend import ToolCallResult +from .types import LLMTelemetryContext + +logger = logging.getLogger(__name__) + +# Sentinel roles for non-message content stored in the shared content store so +# the same hash+dedup machinery covers them. They never collide with real +# conversation roles ("user"/"assistant"/"system"/"tool"). +ROLE_OUTPUT = "assistant" +ROLE_TOOL_SCHEMA = "__tool_schema__" +ROLE_THINKING = "__thinking__" + + +def canonical_json(obj: Any) -> str: + """Deterministic JSON encoding used for every content hash.""" + return json.dumps( + obj, sort_keys=True, separators=(",", ":"), ensure_ascii=False, default=str + ) + + +def compute_content_hash( + role: str, + content: Any, + tool_call_id: str | None, + tool_calls: list[dict[str, Any]] | None = None, +) -> str: + """Content hash covering the FULL message identity, not just the text. + + Includes `tool_calls` so two assistant turns with identical (often empty) + content but different tool calls don't collide in the dedup store. + """ + digest = hashlib.sha256( + canonical_json( + { + "role": role, + "content": content, + "tool_call_id": tool_call_id, + "tool_calls": tool_calls or [], + } + ).encode("utf-8") + ).hexdigest() + return f"sha256:{digest}" + + +def clip_for_trace(content: Any) -> tuple[Any, bool]: + """Clip a content value to `TELEMETRY.TRACE_MAX_BYTES`, returning (content, truncated). + + Only oversized string content is clipped (with a marker); non-string + structured content is left intact. Returns the input unchanged when it + fits or when the cap is non-positive. + """ + max_bytes = settings.TELEMETRY.TRACE_MAX_BYTES + if max_bytes <= 0 or not isinstance(content, str): + return content, False + encoded = content.encode("utf-8") + if len(encoded) <= max_bytes: + return content, False + marker = "…[truncated]" + keep = max(0, max_bytes - len(marker.encode("utf-8"))) + clipped = encoded[:keep].decode("utf-8", errors="ignore") + marker + return clipped, True + + +@dataclass(slots=True) +class CapturedMessage: + """One input message, normalized to a provider-agnostic shape. + + `content` is the message text; `tool_calls` holds any tool calls in a + unified `{id, name, input}` shape regardless of provider. `content_hash` + covers all identity fields so the ref and the shipped `trace.content` agree. + """ + + role: str + content: Any + tool_call_id: str | None + content_hash: str + truncated: bool = False + tool_calls: list[dict[str, Any]] = field(default_factory=list) + + +@dataclass(slots=True) +class CapturedLLMCall: + """Everything one LLM call needs to be reconstructed, captured once.""" + + # Correlation (span tree) + trace_id: str | None + span_id: str | None + parent_span_id: str | None + iteration: int | None + step_seq: int + attempt: int + was_fallback: bool + run_id: str | None + # Path identity + workspace_name: str | None + call_purpose: str | None + parent_category: str | None + agent_type: str | None + # unique session ID for grouping traces + session_id: str | None + observer: str | None + observed: str | None + peer_name: str | None + track_name: str | None + transport: str + provider_label: str | None + model: str + # Context window + input_messages: list[CapturedMessage] + tool_schemas: list[dict[str, Any]] + tool_choice: Any + # Output (replay-grade) + output_content: Any + output_tool_calls: list[dict[str, Any]] + thinking_content: str | None + thinking_blocks: list[dict[str, Any]] + reasoning_details: list[dict[str, Any]] + finish_reason: str | None + # Accounting copy (so the trace stream stands alone) + input_tokens: int + output_tokens: int + cache_read_tokens: int + cache_creation_tokens: int + was_stream: bool + # True when any input message was clipped to TRACE_MAX_BYTES. + input_truncated: bool = False + + +def _normalize_message( + message: dict[str, Any], transport: str | None +) -> tuple[Any, str | None, list[dict[str, Any]]]: + """Normalize a provider-native message to (content, tool_call_id, tool_calls). + + Providers stash tool calls and results outside `content` (openai's + `tool_calls`, gemini's `parts`), so a naive `content` read loses them. This + lifts them into a unified shape: `content` becomes text, `tool_calls` is a + list of `{id, name, input}`, and tool results surface as `content` keyed by + `tool_call_id`. + """ + content: Any = message.get("content") + tool_call_id: str | None = message.get("tool_call_id") + tool_calls: list[dict[str, Any]] = [] + + if transport == "openai": + for tc in cast("list[dict[str, Any]]", message.get("tool_calls") or []): + fn = cast("dict[str, Any]", tc.get("function") or {}) + args = fn.get("arguments") + if isinstance(args, str): + with contextlib.suppress(json.JSONDecodeError): + args = json.loads(args) + tool_calls.append( + {"id": tc.get("id"), "name": fn.get("name"), "input": args} + ) + + elif transport == "gemini": + parts = message.get("parts") + if isinstance(parts, list): + texts: list[str] = [] + results: list[Any] = [] + for raw_part in cast("list[Any]", parts): + if not isinstance(raw_part, dict): + continue + part = cast("dict[str, Any]", raw_part) + text = part.get("text") + if isinstance(text, str): + texts.append(text) + elif "function_call" in part: + fc = cast("dict[str, Any]", part["function_call"] or {}) + tool_calls.append( + {"id": None, "name": fc.get("name"), "input": fc.get("args")} + ) + elif "function_response" in part: + fr = cast("dict[str, Any]", part["function_response"] or {}) + resp = fr.get("response") + if isinstance(resp, dict): + results.append(cast("dict[str, Any]", resp).get("result")) + else: + results.append(resp) + if tool_call_id is None: + tool_call_id = fr.get("name") + content = "\n".join(texts) if texts else (results[0] if results else None) + + elif transport == "anthropic" and isinstance(content, list): + texts = [] + for raw_block in cast("list[Any]", content): + if not isinstance(raw_block, dict): + continue + block = cast("dict[str, Any]", raw_block) + btype = block.get("type") + text = block.get("text") + if btype == "text" and isinstance(text, str): + texts.append(text) + elif btype == "tool_use": + tool_calls.append( + { + "id": block.get("id"), + "name": block.get("name"), + "input": block.get("input"), + } + ) + elif btype == "tool_result": + if tool_call_id is None: + tool_call_id = block.get("tool_use_id") + inner = block.get("content") + texts.append(inner if isinstance(inner, str) else canonical_json(inner)) + content = "\n".join(texts) if texts else None + + return content, tool_call_id, tool_calls + + +def build_captured_messages( + messages: list[dict[str, Any]], + memo: dict[int, CapturedMessage] | None, + transport: str | None = None, +) -> tuple[list[CapturedMessage], bool]: + """Create a list of CapturedMessage from LLM response messages. + + Conversation is append-only. Uses hashed message content to deduplicate + across turns. Messages are normalized per provider, then content is + truncated and hashed. + """ + captured: list[CapturedMessage] = [] + any_truncated = False + for message in messages: + key = id(message) + cached = memo.get(key) if memo is not None else None + if cached is not None: + captured.append(cached) + any_truncated = any_truncated or cached.truncated + continue + role = str(message.get("role", "")) + raw_content, tool_call_id, tool_calls = _normalize_message(message, transport) + content, truncated = clip_for_trace(raw_content) + any_truncated = any_truncated or truncated + captured_message = CapturedMessage( + role=role, + content=content, + tool_call_id=tool_call_id, + content_hash=compute_content_hash(role, content, tool_call_id, tool_calls), + truncated=truncated, + tool_calls=tool_calls, + ) + if memo is not None: + memo[key] = captured_message + captured.append(captured_message) + return captured, any_truncated + + +def build_captured_call( + *, + telemetry: LLMTelemetryContext | None, + transport: str, + provider_label: str | None, + model: str, + messages: list[dict[str, Any]], + tools: list[dict[str, Any]] | None, + tool_choice: Any, + result: BackendCompletionResult | None, + attempt: int, + was_fallback: bool, + was_stream: bool, + finish_reason: str | None, +) -> CapturedLLMCall: + """Assemble a `CapturedLLMCall` from telemetry + the provider result.""" + memo = telemetry.hash_memo if telemetry is not None else None + captured_messages, input_truncated = build_captured_messages( + messages, memo, transport + ) + + output_tool_calls = [ + _tool_call_to_dict(tc) for tc in (result.tool_calls if result else []) + ] + + return CapturedLLMCall( + trace_id=telemetry.trace_id if telemetry else None, + span_id=telemetry.span_id if telemetry else None, + parent_span_id=telemetry.exported_parent_span_id() if telemetry else None, + iteration=telemetry.iteration if telemetry else None, + step_seq=telemetry.step_seq if telemetry else 0, + attempt=attempt, + was_fallback=was_fallback, + run_id=telemetry.run_id if telemetry else None, + workspace_name=telemetry.workspace_name if telemetry else None, + call_purpose=telemetry.call_purpose if telemetry else None, + parent_category=telemetry.parent_category if telemetry else None, + agent_type=telemetry.agent_type if telemetry else None, + session_id=telemetry.session_id if telemetry else None, + observer=telemetry.observer if telemetry else None, + observed=telemetry.observed if telemetry else None, + peer_name=telemetry.peer_name if telemetry else None, + track_name=telemetry.track_name if telemetry else None, + transport=transport, + provider_label=provider_label, + model=model, + input_messages=captured_messages, + tool_schemas=list(tools) if tools else [], + tool_choice=tool_choice, + output_content=result.content if result else None, + output_tool_calls=output_tool_calls, + thinking_content=result.thinking_content if result else None, + thinking_blocks=result.thinking_blocks if result else [], + reasoning_details=result.reasoning_details if result else [], + finish_reason=finish_reason, + input_tokens=result.input_tokens if result else 0, + output_tokens=result.output_tokens if result else 0, + cache_read_tokens=result.cache_read_input_tokens if result else 0, + cache_creation_tokens=result.cache_creation_input_tokens if result else 0, + was_stream=was_stream, + input_truncated=input_truncated, + ) + + +def _tool_call_to_dict(tool_call: ToolCallResult) -> dict[str, Any]: + """Normalize a ToolCallResult to a JSON-safe dict for the trace stream. + + `thought_signature` arrives as raw bytes from Gemini; base64-encode it so + CloudEvents JSON serialization can't choke on non-UTF8 bytes (which would + silently drop the whole event via the best-effort emit path). + """ + out: dict[str, Any] = { + "id": tool_call.id, + "name": tool_call.name, + "input": tool_call.input, + } + sig = tool_call.thought_signature + if sig is not None: + out["thought_signature"] = ( + base64.b64encode(sig).decode("ascii") if isinstance(sig, bytes) else sig + ) + return out + + +@runtime_checkable +class LLMCallExporter(Protocol): + """A sink that consumes a `CapturedLLMCall`""" + + def export(self, call: CapturedLLMCall) -> None: ... + + +_EXPORTERS: list[LLMCallExporter] = [] + + +def register_exporter(exporter: LLMCallExporter) -> None: + """Register an exporter (idempotent on identity). Called at startup.""" + if exporter not in _EXPORTERS: + _EXPORTERS.append(exporter) + + +def clear_exporters() -> None: + """Drop all exporters — used on shutdown and in tests.""" + _EXPORTERS.clear() + + +def has_exporters() -> bool: + """True when at least one exporter is registered.""" + return bool(_EXPORTERS) + + +def dispatch_captured_call(call: CapturedLLMCall) -> None: + """Fan a captured call out to every exporter.""" + for exporter in _EXPORTERS: + try: + exporter.export(call) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug("LLM call exporter failed", exc_info=True) + + +__all__ = [ + "ROLE_OUTPUT", + "ROLE_THINKING", + "ROLE_TOOL_SCHEMA", + "CapturedLLMCall", + "CapturedMessage", + "LLMCallExporter", + "build_captured_call", + "build_captured_messages", + "canonical_json", + "clear_exporters", + "clip_for_trace", + "compute_content_hash", + "dispatch_captured_call", + "has_exporters", + "register_exporter", +] diff --git a/src/llm/executor.py b/src/llm/executor.py index 017ce669..956bc673 100644 --- a/src/llm/executor.py +++ b/src/llm/executor.py @@ -25,6 +25,7 @@ from src.telemetry.logging import conditional_observe from .backend import CompletionResult as BackendCompletionResult from .backend import StreamChunk as BackendStreamChunk from .backend import ToolCallResult +from .capture import build_captured_call, dispatch_captured_call, has_exporters from .registry import CLIENTS, backend_for_provider from .request_builder import execute_completion, execute_stream from .runtime import ( @@ -138,7 +139,7 @@ def _outcome_from_error( def _tool_call_result_to_dict(tool_call: ToolCallResult) -> dict[str, Any]: - result = { + result: dict[str, Any] = { "id": tool_call.id, "name": tool_call.name, "input": tool_call.input, @@ -189,7 +190,7 @@ def _emit_llm_call_completed( call_purpose=call_purpose, parent_category=(telemetry.parent_category if telemetry else None), transport=provider, - provider_label=_infer_provider_label(provider, model, plan), + provider_label=infer_provider_label(provider, model, plan), model=model, effective_max_output_tokens=max_tokens, provider_input_tokens=(result.input_tokens if result else 0), @@ -217,7 +218,7 @@ def _emit_llm_call_completed( logger.debug("Failed to emit LLMCallCompletedEvent", exc_info=True) -def _infer_provider_label( +def infer_provider_label( _transport: ModelTransport, model: str, plan: AttemptPlan | None ) -> str | None: """Best-effort vendor inference for relay setups. @@ -243,6 +244,49 @@ def _infer_provider_label( return None +def _maybe_dispatch_capture( + *, + plan: AttemptPlan | None, + telemetry: LLMTelemetryContext | None, + provider: ModelTransport, + model: str, + messages: list[dict[str, Any]], + tools: list[dict[str, Any]] | None, + tool_choice: Any, + result: BackendCompletionResult | None, + error: BaseException | None, +) -> None: + """Build a CapturedLLMCall and fan it out to registered exporters. + + No-op when payload capture is off + `has_exporters()` is checked BEFORE building. + Best-effort: never raises into the call path. + """ + if not has_exporters(): + return + try: + outcome = _outcome_from_error(error) + finish_reason = result.finish_reason if result is not None else outcome + dispatch_captured_call( + build_captured_call( + telemetry=telemetry, + transport=str(provider), + provider_label=infer_provider_label(provider, model, plan), + model=model, + messages=messages, + tools=tools, + tool_choice=tool_choice, + result=result, + attempt=plan.attempt if plan is not None else 1, + was_fallback=plan.is_fallback if plan is not None else False, + was_stream=False, + finish_reason=finish_reason, + ) + ) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug("Failed to dispatch CapturedLLMCall", exc_info=True) + + def completion_result_to_response( result: BackendCompletionResult, ) -> HonchoLLMCallResponse[Any]: @@ -422,10 +466,11 @@ async def honcho_llm_call_inner( # Explicit generation input + tuning knobs (replaces @observe auto-capture, # which would serialize the live client / api key). Set before the stream - # branch so it lands on the generation span for both paths. Guard on the - # public key so we don't build the (model_dump-backed) payload when Langfuse - # is disabled — the annotate helper no-ops, but the payload still costs. - if settings.LANGFUSE_PUBLIC_KEY: + # branch so it lands on the generation span for both paths. Guard on inline + # mode (matching annotate_current_generation_io's own gate) so we don't + # build the (model_dump-backed) payload when the helper would no-op — in + # exporter mode there's no active generation span to stamp. + if settings.langfuse_inline_enabled: annotate_current_generation_io( input=messages, model_parameters=_langfuse_model_parameters( @@ -528,8 +573,7 @@ async def honcho_llm_call_inner( # Explicit generation output + token usage (replaces @observe # auto-capture). The stream path closes this span before drain, so its # output is stamped on the run-level span instead - # (StreamingResponseWithMetadata). - if settings.LANGFUSE_PUBLIC_KEY: + if settings.langfuse_inline_enabled: annotate_current_generation_io( output=response, usage_details=_langfuse_usage_details(response), @@ -552,6 +596,17 @@ async def honcho_llm_call_inner( result=backend_result, error=error, ) + _maybe_dispatch_capture( + plan=plan, + telemetry=telemetry, + provider=provider, + model=model, + messages=messages, + tools=tools, + tool_choice=tool_choice, + result=backend_result, + error=error, + ) __all__ = [ diff --git a/src/llm/runtime.py b/src/llm/runtime.py index ec07acf8..93e961c9 100644 --- a/src/llm/runtime.py +++ b/src/llm/runtime.py @@ -33,14 +33,6 @@ logger = logging.getLogger(__name__) # ContextVar tracking the current retry attempt for provider switching. current_attempt: ContextVar[int] = ContextVar("current_attempt", default=0) -# True while a `LangfuseAgentRun` handle is live (start → end). Set by -# `start_langfuse_agent_run`, reset by `LangfuseAgentRun.end`. Used by -# `annotate_current_langfuse_trace` to decide whether the current generation -# is the trace root (single-shot callers like the deriver — stamp trace attrs) -# or nested under an active run (multi-turn / streaming — skip trace attrs; -# the run span already carries them via `propagate_attributes`). -_in_agent_run: ContextVar[bool] = ContextVar("_in_agent_run", default=False) - def annotate_current_langfuse_trace( provider: ModelTransport, @@ -56,16 +48,16 @@ def annotate_current_langfuse_trace( callers — deriver, summarizer), this generation IS the trace root, so we also stamp the trace attrs. - Note: `model`/`metadata` are set on every call regardless of `inside_run` - so multi-turn iterations no longer lose provider/model attribution. + `model`/`metadata` are set on every call regardless of `inside_run`, so + every multi-turn iteration carries provider/model attribution. """ - if not settings.LANGFUSE_PUBLIC_KEY: + if not settings.langfuse_inline_enabled: return try: from langfuse import get_client, propagate_attributes - inside_run = _in_agent_run.get() + inside_run = telemetry is not None and telemetry.parent_span_id is not None gen_metadata = _step_metadata(telemetry) if telemetry is not None else {} gen_metadata["provider"] = str(provider) gen_metadata["model"] = str(model) @@ -76,7 +68,7 @@ def annotate_current_langfuse_trace( ) if not inside_run: - run_id = telemetry.run_id if telemetry is not None else None + session_id = telemetry.span_identity() if telemetry is not None else None trace_name = telemetry.track_name if telemetry is not None else None trace_metadata: dict[str, str] = dict(gen_metadata) if telemetry is None: @@ -87,7 +79,7 @@ def annotate_current_langfuse_trace( # dead code — the enter-time side effect is the point. with propagate_attributes( user_id=str(settings.NAMESPACE), - session_id=run_id, + session_id=session_id, trace_name=trace_name, metadata=trace_metadata, ): @@ -123,7 +115,10 @@ def annotate_current_generation_io( Best-effort: telemetry must never fail the LLM call. """ - if not settings.LANGFUSE_PUBLIC_KEY: + # Gated on inline mode (NOT just key presence): this writes to the *active* + # @observe generation span, which only exists in inline mode. In exporter + # mode `conditional_observe` applies no decorator. + if not settings.langfuse_inline_enabled: return payload: dict[str, Any] = {} if input is not None: @@ -157,6 +152,9 @@ def _base_metadata(telemetry: LLMTelemetryContext) -> dict[str, str]: ("observer", telemetry.observer), ("observed", telemetry.observed), ("peer_name", telemetry.peer_name), + ("trace_id", telemetry.trace_id), + ("span_id", telemetry.span_id), + ("parent_span_id", telemetry.exported_parent_span_id()), ): if value is not None: metadata[key] = str(value) @@ -167,10 +165,13 @@ def _step_metadata( telemetry: LLMTelemetryContext, base: dict[str, str] | None = None, ) -> dict[str, str]: - """Per-step metadata: ``base`` (or freshly computed) plus ``iteration``.""" + """Per-step metadata: ``base`` (or freshly computed) plus the per-step + ``iteration`` / ``step_seq`` / ``attempt`` counters.""" metadata = dict(base) if base is not None else _base_metadata(telemetry) if telemetry.iteration is not None: metadata["iteration"] = str(telemetry.iteration) + metadata["step_seq"] = str(telemetry.step_seq) + metadata["attempt"] = str(telemetry.attempt) return metadata @@ -191,7 +192,6 @@ class LangfuseAgentRun: span: Any # LangfuseSpan; opaque to keep src/llm/ free of langfuse imports. _stack: ExitStack - _run_token: Any _ended: bool = field(default=False) def update(self, **kwargs: Any) -> None: @@ -217,12 +217,6 @@ class LangfuseAgentRun: self._stack.close() except Exception as exc: # pragma: no cover - best-effort telemetry logger.debug("Failed to close Langfuse run span: %s", exc) - try: - _in_agent_run.reset(self._run_token) - except (ValueError, LookupError) as exc: # pragma: no cover - # ContextVar.reset can raise if end() runs in a different async - # context than start(); telemetry must not fail user code. - logger.debug("Failed to reset _in_agent_run: %s", exc) def start_langfuse_agent_run( @@ -230,13 +224,16 @@ def start_langfuse_agent_run( ) -> LangfuseAgentRun | None: """Open the one run-level Langfuse trace per agentic run, imperatively. - Returns ``None`` when Langfuse is disabled or there's no ``run_id`` - (single-shot callers — those self-stamp via - ``annotate_current_langfuse_trace``). When non-None, the caller MUST + Returns ``None`` when Langfuse is disabled or there's no span identity + (single-shot callers without a ``span_id``/``run_id`` — those self-stamp + via ``annotate_current_langfuse_trace``). When non-None, the caller MUST eventually call ``.end()`` — typically in a ``finally`` block, or by transferring ownership to the streaming wrapper. """ - if not settings.LANGFUSE_PUBLIC_KEY or telemetry is None or not telemetry.run_id: + if not settings.langfuse_inline_enabled or telemetry is None: + return None + session_id = telemetry.span_identity() + if not session_id: return None stack = ExitStack() try: @@ -248,7 +245,7 @@ def start_langfuse_agent_run( stack.enter_context( propagate_attributes( user_id=str(settings.NAMESPACE), - session_id=telemetry.run_id, + session_id=session_id, trace_name=name, metadata=_base_metadata(telemetry), ) @@ -258,8 +255,7 @@ def start_langfuse_agent_run( stack.close() return None - run_token = _in_agent_run.set(True) - return LangfuseAgentRun(span=span, _stack=stack, _run_token=run_token) + return LangfuseAgentRun(span=span, _stack=stack) @dataclass @@ -328,9 +324,11 @@ def start_langfuse_agent_step( name: str, telemetry: LLMTelemetryContext | None ) -> LangfuseAgentStep | None: """Open a per-iteration step span, imperatively. Returns ``None`` when - Langfuse is disabled or there's no ``run_id`` (no agent run to nest under). + Langfuse is disabled or there's no span identity (no agent run to nest under). """ - if not settings.LANGFUSE_PUBLIC_KEY or telemetry is None or not telemetry.run_id: + if not settings.langfuse_inline_enabled or telemetry is None: + return None + if not telemetry.span_identity(): return None stack = ExitStack() try: diff --git a/src/llm/tool_loop.py b/src/llm/tool_loop.py index 34fdba26..0feec1d8 100644 --- a/src/llm/tool_loop.py +++ b/src/llm/tool_loop.py @@ -30,7 +30,12 @@ from src.utils.types import ( set_last_tool_metadata, ) -from .executor import honcho_llm_call_inner +from .capture import ( + build_captured_call, + dispatch_captured_call, + has_exporters, +) +from .executor import honcho_llm_call_inner, infer_provider_label from .registry import history_adapter_for_provider from .runtime import ( AttemptPlan, @@ -81,17 +86,67 @@ def _step_label(base: LLMTelemetryContext | None) -> str: def _telemetry_for_iteration( - base: LLMTelemetryContext | None, iteration: int + base: LLMTelemetryContext | None, + iteration: int, + *, + step_seq: int, ) -> LLMTelemetryContext | None: - """Return a copy of `base` with `iteration` set, or None if no base. + """Return a copy of `base` with per-step correlation set, or None if no base. We always copy rather than mutate the caller-supplied context so callers that pass the same context into multiple `honcho_llm_call` invocations - don't see drift across concurrent runs. + don't see drift across concurrent runs. `parent_span_id` is set to the + span being looped over (`base.span_id`) so nested generations are correctly + treated as children of the run span. """ if base is None: return None - return dataclasses.replace(base, iteration=iteration) + return dataclasses.replace( + base, + iteration=iteration, + step_seq=step_seq, + parent_span_id=base.span_identity(), + ) + + +def _make_stream_capture_finalizer( + telemetry: LLMTelemetryContext | None, + plan: AttemptPlan, + messages: list[dict[str, Any]], +) -> Callable[[str, str], None] | None: + """Build the streamed-call capture finalizer, or None when capture is off. + + Snapshots the input messages now and returns a closure the streaming wrapper + calls on drain with `(streamed_text, finish_reason)`. Tool calls already ran + in the loop, so the final streamed turn is text-only. Returns None when no + exporter is registered. + """ + if not has_exporters(): + return None + captured_messages = list(messages) + + def _finalize(text: str, finish_reason: str) -> None: + from .backend import CompletionResult as BackendCompletionResult + + result = BackendCompletionResult(content=text, finish_reason=finish_reason) + dispatch_captured_call( + build_captured_call( + telemetry=telemetry, + transport=str(plan.provider), + provider_label=infer_provider_label(plan.provider, plan.model, plan), + model=plan.model, + messages=captured_messages, + tools=None, + tool_choice=None, + result=result, + attempt=plan.attempt, + was_fallback=plan.is_fallback, + was_stream=True, + finish_reason=finish_reason, + ) + ) + + return _finalize def _emit_agent_iteration( @@ -328,6 +383,12 @@ async def execute_tool_loop( messages.copy() if messages else [{"role": "user", "content": prompt}] ) + # Seed one hash memo for the whole span. dataclasses.replace copies the dict reference into + # every per-iteration telemetry copy, so each appended message is content-hashed exactly once + # across the span. + if telemetry is not None and telemetry.hash_memo is None: + telemetry = dataclasses.replace(telemetry, hash_memo={}) + iteration = 0 all_tool_calls: list[dict[str, Any]] = [] total_input_tokens = 0 @@ -349,7 +410,7 @@ async def execute_tool_loop( while iteration < max_tool_iterations: step = start_langfuse_agent_step( _step_label(telemetry), - _telemetry_for_iteration(telemetry, iteration + 1), + _telemetry_for_iteration(telemetry, iteration + 1, step_seq=iteration + 1), ) try: # Reset attempt counter so each iteration starts with the primary provider. @@ -392,7 +453,9 @@ async def execute_tool_loop( messages=captured_messages, selected_config=plan.selected_config, plan=plan, - telemetry=_telemetry_for_iteration(telemetry, iteration_for_call), + telemetry=_telemetry_for_iteration( + telemetry, iteration_for_call, step_seq=iteration_for_call + ), ) call_func: Callable[[], Awaitable[HonchoLLMCallResponse[Any]]] @@ -453,6 +516,13 @@ async def execute_tool_loop( # pin to this exact client/model so we don't bounce back to # primary after the tool loop settled on fallback. winning_plan = get_attempt_plan() + # +2 (not +1): the in-loop call we just made used iteration+1, + # so the streamed tail needs the next ordinal — otherwise its + # trace resource id collides with that call's. Mirrors the + # synthesis path's distinct-next-value behavior. + stream_telemetry = _telemetry_for_iteration( + telemetry, iteration + 2, step_seq=iteration + 2 + ) stream = stream_final_response( winning_plan=winning_plan, prompt=prompt, @@ -466,7 +536,7 @@ async def execute_tool_loop( enable_retry=enable_retry, retry_attempts=retry_attempts, before_retry_callback=before_retry_callback, - telemetry=_telemetry_for_iteration(telemetry, iteration + 1), + telemetry=stream_telemetry, ) return StreamingResponseWithMetadata( stream=stream, @@ -479,6 +549,9 @@ async def execute_tool_loop( iterations=iteration + 1, hit_input_token_cap=hit_input_token_cap, langfuse_run_handle=langfuse_run_handle, + capture_finalizer=_make_stream_capture_finalizer( + stream_telemetry, winning_plan, conversation_messages + ), ) response.tool_calls_made = all_tool_calls @@ -612,6 +685,9 @@ async def execute_tool_loop( # Snapshot the plan the loop settled on — streaming retries pin to # this exact client/model rather than re-running provider selection. winning_plan = get_attempt_plan() + stream_telemetry = _telemetry_for_iteration( + telemetry, synthesis_iteration, step_seq=synthesis_iteration + ) stream = stream_final_response( winning_plan=winning_plan, prompt=prompt, @@ -625,7 +701,7 @@ async def execute_tool_loop( enable_retry=enable_retry, retry_attempts=retry_attempts, before_retry_callback=before_retry_callback, - telemetry=_telemetry_for_iteration(telemetry, synthesis_iteration), + telemetry=stream_telemetry, ) return StreamingResponseWithMetadata( stream=stream, @@ -638,6 +714,9 @@ async def execute_tool_loop( iterations=iteration + 1, hit_input_token_cap=hit_input_token_cap, langfuse_run_handle=langfuse_run_handle, + capture_finalizer=_make_stream_capture_finalizer( + stream_telemetry, winning_plan, conversation_messages + ), ) current_attempt.set(1) @@ -663,7 +742,9 @@ async def execute_tool_loop( messages=conversation_messages, selected_config=plan.selected_config, plan=plan, - telemetry=_telemetry_for_iteration(telemetry, synthesis_iteration), + telemetry=_telemetry_for_iteration( + telemetry, synthesis_iteration, step_seq=synthesis_iteration + ), ) if enable_retry: @@ -680,7 +761,9 @@ async def execute_tool_loop( # trace. Imperative pair with a try/finally for the .end(). synthesis_step = start_langfuse_agent_step( _step_label(telemetry), - _telemetry_for_iteration(telemetry, synthesis_iteration), + _telemetry_for_iteration( + telemetry, synthesis_iteration, step_seq=synthesis_iteration + ), ) try: final_response = await final_call_func() @@ -692,7 +775,9 @@ async def execute_tool_loop( # totals onto final_response below — otherwise the event's per-iteration # token counts would double-count the running totals. _emit_agent_iteration( - _telemetry_for_iteration(telemetry, synthesis_iteration), + _telemetry_for_iteration( + telemetry, synthesis_iteration, step_seq=synthesis_iteration + ), synthesis_iteration, final_response, ) diff --git a/src/llm/types.py b/src/llm/types.py index 8b394dd3..33058e09 100644 --- a/src/llm/types.py +++ b/src/llm/types.py @@ -6,15 +6,22 @@ of the migration toward src/llm/ owning all non-embedding LLM orchestration. from __future__ import annotations +import asyncio +import logging from collections.abc import AsyncIterator, Callable -from dataclasses import dataclass -from typing import Any, Generic, Literal, TypeVar +from dataclasses import dataclass, field +from typing import TYPE_CHECKING, Any, Generic, Literal, TypeVar from anthropic import AsyncAnthropic from google import genai from openai import AsyncOpenAI from pydantic import BaseModel, Field +if TYPE_CHECKING: + from src.llm.capture import CapturedMessage + +logger = logging.getLogger(__name__) + T = TypeVar("T") # OpenAI GPT-5 specific reasoning levels. @@ -65,12 +72,23 @@ class LLMTelemetryContext: parent_category: str | None = None run_id: str | None = None iteration: int | None = None + # OpenTelemetry-style span-tree correlation. + trace_id: str | None = None + span_id: str | None = None + parent_span_id: str | None = None + # Monotonic executor-call ordinal WITHIN a span (total ordering of its + # steps). + step_seq: int = 0 + # Retry/fallback attempt within an iteration. + attempt: int = 1 # Optional peer context (dream agents pass observer/observed; dialectic # passes peer_name). Kept here so AgentIterationEvent can populate # them without a separate threading path. observer: str | None = None observed: str | None = None peer_name: str | None = None + # Used to group traces (should not use session_name because it is not unique) + session_id: str | None = None # Tool-related context: agent_type is the human-readable identifier of the # agent — dialectic/deduction/induction. Used by agent iteration # event and tool call event. @@ -81,6 +99,19 @@ class LLMTelemetryContext: # Also used to label the sentry `ai_track` decorator and as the source for # the run-level `langfuse_agent_run` label. track_name: str | None = None + # Per-span memo for O(N) message capture in CapturedLLMCall + hash_memo: dict[int, CapturedMessage] | None = field( + default=None, compare=False, repr=False + ) + + def span_identity(self) -> str | None: + """Effective span id: the new `span_id`, falling back to legacy `run_id`.""" + return self.span_id or self.run_id + + def exported_parent_span_id(self) -> str | None: + """`parent_span_id` for EXPORT, collapsing the self-parent sentinel to None.""" + pid = self.parent_span_id + return None if pid is not None and pid == self.span_id else pid IterationCallback = Callable[[IterationData], None] @@ -147,6 +178,13 @@ class StreamingResponseWithMetadata: as the run span's output and the span is closed. Without this transfer, streaming traces would show blank output because the synchronous return happens before any chunks arrive. + + `capture_finalizer` (optional) closes the replay-grade content capture for + a streamed call. The synchronous return happens before any chunks arrive, + so the streamed text only exists once the stream drains — the wrapper calls + the finalizer with `(accumulated_text, finish_reason)` in its `finally`. + A partial/aborted stream still finalizes, with `finish_reason` = + "cancelled"/"error". """ _stream: AsyncIterator[HonchoLLMCallStreamChunk] @@ -159,6 +197,7 @@ class StreamingResponseWithMetadata: iterations: int hit_input_token_cap: bool _langfuse_run_handle: Any | None + _capture_finalizer: Callable[[str, str], None] | None def __init__( self, @@ -172,6 +211,7 @@ class StreamingResponseWithMetadata: iterations: int = 0, hit_input_token_cap: bool = False, langfuse_run_handle: Any | None = None, + capture_finalizer: Callable[[str, str], None] | None = None, ): self._stream = stream self.tool_calls_made = tool_calls_made @@ -183,6 +223,7 @@ class StreamingResponseWithMetadata: self.iterations = iterations self.hit_input_token_cap = hit_input_token_cap self._langfuse_run_handle = langfuse_run_handle + self._capture_finalizer = capture_finalizer def __aiter__(self) -> AsyncIterator[HonchoLLMCallStreamChunk]: # Wrap the underlying iterator to capture final-stream output_tokens @@ -196,16 +237,23 @@ class StreamingResponseWithMetadata: self, ) -> AsyncIterator[HonchoLLMCallStreamChunk]: final_stream_output_tokens = 0 - # Only accumulate when a Langfuse run handle is attached — for non- - # traced streams the buffer is dead weight. - accumulate = self._langfuse_run_handle is not None + # Accumulate the streamed text when either consumer needs it: the + # Langfuse run span (stamped as output on drain) or the content-capture + # finalizer. + accumulate = ( + self._langfuse_run_handle is not None or self._capture_finalizer is not None + ) accumulated_text: list[str] = [] + last_finish_reason: str | None = None + stream_error: BaseException | None = None try: async for chunk in self._stream: if chunk.output_tokens is not None: # Take the LATEST value, not the sum — providers report # the cumulative usage in the final chunk, not deltas. final_stream_output_tokens = chunk.output_tokens + if chunk.finish_reasons: + last_finish_reason = chunk.finish_reasons[-1] if accumulate and chunk.content: accumulated_text.append(chunk.content) yield chunk @@ -214,14 +262,36 @@ class StreamingResponseWithMetadata: # see the true cost. if final_stream_output_tokens > 0: self.output_tokens += final_stream_output_tokens + except BaseException as exc: + stream_error = exc + raise finally: + text = "".join(accumulated_text) # Close the run span once, stamping the streamed text as its # output. In `finally` so an early-exit caller still closes # the span rather than leaking it. handle = self._langfuse_run_handle if handle is not None: self._langfuse_run_handle = None - handle.end(output="".join(accumulated_text) or None) + handle.end(output=text or None) + # Finalize the content capture with the full streamed text. Even a + # partial/aborted stream captures, tagged with the right outcome. + finalizer = self._capture_finalizer + if finalizer is not None: + self._capture_finalizer = None + finish_reason = ( + (last_finish_reason or "stop") + if stream_error is None + else ( + "cancelled" + if isinstance(stream_error, asyncio.CancelledError) + else "error" + ) + ) + try: + finalizer(text, finish_reason) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug("Stream capture finalizer failed", exc_info=True) __all__ = [ diff --git a/src/telemetry/__init__.py b/src/telemetry/__init__.py index 68e79773..03cc9e0c 100644 --- a/src/telemetry/__init__.py +++ b/src/telemetry/__init__.py @@ -42,6 +42,8 @@ async def initialize_telemetry_async() -> None: from src.config import settings from src.telemetry.events import initialize_telemetry_events + # Master switch for every trace sink, Langfuse included: telemetry off + # initializes nothing. if settings.TELEMETRY.ENABLED: await initialize_telemetry_events() diff --git a/src/telemetry/emitter.py b/src/telemetry/emitter.py index 2413c7c2..201d16aa 100644 --- a/src/telemetry/emitter.py +++ b/src/telemetry/emitter.py @@ -100,6 +100,7 @@ class TelemetryEmitter: max_retries: int max_buffer_size: int enabled: bool + drop_reason_prefix: str _buffer: deque[CloudEvent] _flush_task: asyncio.Task[None] | None _client: httpx.AsyncClient | None @@ -118,6 +119,7 @@ class TelemetryEmitter: max_retries: int = 3, max_buffer_size: int = 10000, enabled: bool = True, + drop_reason_prefix: str = "", ): """Initialize the telemetry emitter. @@ -130,6 +132,9 @@ class TelemetryEmitter: max_retries: Maximum retry attempts on failure max_buffer_size: Maximum events to buffer (oldest dropped if exceeded) enabled: Whether emission is enabled + drop_reason_prefix: Prefix for the dropped-event metric reason label + (e.g. "trace_") so a second emitter's drops are distinguishable + from the primary metrics emitter's in Prometheus. """ self.endpoint = endpoint self.headers = headers or {} @@ -139,6 +144,7 @@ class TelemetryEmitter: self.max_retries = max_retries self.max_buffer_size = max_buffer_size self.enabled = enabled and endpoint is not None + self.drop_reason_prefix = drop_reason_prefix self._buffer = deque(maxlen=max_buffer_size) self._flush_task = None @@ -292,7 +298,9 @@ class TelemetryEmitter: cloud_event = CloudEvent(attributes, body) if will_drop_oldest: - prometheus_metrics.record_telemetry_event_dropped(reason="buffer_full") + prometheus_metrics.record_telemetry_event_dropped( + reason=f"{self.drop_reason_prefix}buffer_full" + ) self._buffer.append(cloud_event) buffer_size = len(self._buffer) @@ -375,7 +383,7 @@ class TelemetryEmitter: for event in reversed(batch): if len(self._buffer) >= self.max_buffer_size: prometheus_metrics.record_telemetry_event_dropped( - reason="send_failed" + reason=f"{self.drop_reason_prefix}send_failed" ) self._buffer.appendleft(event) logger.warning( @@ -527,3 +535,54 @@ async def shutdown_emitter() -> None: if _emitter is not None: await _emitter.shutdown() _emitter = None + + +# Separate emitter for the full-fidelity trace stream (llm.call.traced / +# trace.content). Kept distinct from the metrics `_emitter` so a trace burst +# can never evict billing events from the metrics buffer. +_trace_emitter: TelemetryEmitter | None = None + + +def get_trace_emitter() -> TelemetryEmitter | None: + """Get the global trace-stream emitter instance (None when payload tracing off).""" + return _trace_emitter + + +async def initialize_trace_emitter( + endpoint: str | None = None, + headers: dict[str, str] | None = None, + batch_size: int = 100, + flush_interval_seconds: float = 1.0, + flush_threshold: int = 50, + max_retries: int = 3, + max_buffer_size: int = 10000, + enabled: bool = True, +) -> TelemetryEmitter: + """Initialize and start the global trace-stream emitter. + + Drops are recorded under the ``trace_`` reason prefix so they're + distinguishable from the metrics emitter's drops in Prometheus. + """ + global _trace_emitter + + _trace_emitter = TelemetryEmitter( + endpoint=endpoint, + headers=headers, + batch_size=batch_size, + flush_interval_seconds=flush_interval_seconds, + flush_threshold=flush_threshold, + max_retries=max_retries, + max_buffer_size=max_buffer_size, + enabled=enabled, + drop_reason_prefix="trace_", + ) + await _trace_emitter.start() + return _trace_emitter + + +async def shutdown_trace_emitter() -> None: + """Shutdown the global trace-stream emitter.""" + global _trace_emitter + if _trace_emitter is not None: + await _trace_emitter.shutdown() + _trace_emitter = None diff --git a/src/telemetry/events/__init__.py b/src/telemetry/events/__init__.py index 3da745dd..000e70b4 100644 --- a/src/telemetry/events/__init__.py +++ b/src/telemetry/events/__init__.py @@ -89,6 +89,11 @@ from src.telemetry.events.reconciliation import ( SyncVectorsCompletedEvent, ) from src.telemetry.events.representation import RepresentationCompletedEvent +from src.telemetry.events.trace import ( + EmbeddingCallTracedEvent, + LLMCallTracedEvent, + TraceContentEvent, +) logger = logging.getLogger(__name__) @@ -120,6 +125,11 @@ __all__ = [ "CallPurpose", "EmbeddingCallCompletedEvent", "EmbeddingCallPurpose", + # Trace (full-fidelity payload) events + "emit_trace", + "EmbeddingCallTracedEvent", + "LLMCallTracedEvent", + "TraceContentEvent", # Reconciliation events "SyncVectorsCompletedEvent", "CleanupStaleItemsCompletedEvent", @@ -172,6 +182,27 @@ def emit(event: BaseEvent) -> None: ) +def emit_trace(event: BaseEvent) -> None: + """Queue a payload-trace event on the SEPARATE trace emitter. + + Distinct from `emit()` so a trace burst can never evict billing events from + the metrics buffer. No-op when payload tracing is off (trace emitter None). + Best-effort — swallows failures so telemetry never breaks the LLM path. + """ + try: + from src.telemetry.emitter import get_trace_emitter + + emitter = get_trace_emitter() + if emitter is None: + logger.debug("Trace emitter not initialized, dropping trace event") + return + emitter.emit(event) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug( + "Failed to emit trace event %s", type(event).__name__, exc_info=True + ) + + async def initialize_telemetry_events() -> None: """Initialize the telemetry events system based on configuration. @@ -188,6 +219,17 @@ async def initialize_telemetry_events() -> None: logger.info("CloudEvents telemetry disabled") return + # Langfuse as a projection over the captured LLM stream. Gated behind the + # telemetry master switch above, so disabling telemetry disables Langfuse + # too. Registering the exporter makes has_exporters() true, which is what + # turns on CapturedLLMCall building. + if settings.langfuse_exporter_enabled: + from src.llm.capture import register_exporter + from src.telemetry.langfuse_exporter import LangfuseExporter + + register_exporter(LangfuseExporter()) + logger.info("Langfuse exporter registered (LANGFUSE_EXPORTER_MODE=exporter)") + await initialize_emitter( endpoint=settings.TELEMETRY.ENDPOINT, headers=settings.TELEMETRY.HEADERS, @@ -203,6 +245,27 @@ async def initialize_telemetry_events() -> None: "CloudEvents telemetry initialized, endpoint: %s", settings.TELEMETRY.ENDPOINT ) + # Full-fidelity payload tracing — opt-in, separate emitter + content exporter. + if settings.TELEMETRY.TRACE_PAYLOADS_ENABLED: + from src.llm.capture import register_exporter + from src.telemetry.emitter import initialize_trace_emitter + from src.telemetry.trace_exporter import TraceExporter + + await initialize_trace_emitter( + endpoint=settings.TELEMETRY.ENDPOINT, + headers=settings.TELEMETRY.HEADERS, + batch_size=settings.TELEMETRY.BATCH_SIZE, + flush_interval_seconds=settings.TELEMETRY.FLUSH_INTERVAL_SECONDS, + flush_threshold=settings.TELEMETRY.FLUSH_THRESHOLD, + max_retries=settings.TELEMETRY.MAX_RETRIES, + max_buffer_size=settings.TELEMETRY.MAX_BUFFER_SIZE, + enabled=True, + ) + register_exporter(TraceExporter()) + logger.info( + "Payload tracing initialized, endpoint: %s", settings.TELEMETRY.ENDPOINT + ) + async def shutdown_telemetry_events() -> None: """Shutdown the telemetry events system. @@ -210,7 +273,16 @@ async def shutdown_telemetry_events() -> None: This should be called during application shutdown to ensure all buffered events are flushed before exit. """ - from src.telemetry.emitter import shutdown_emitter + # Tear down the trace path first (flush its buffer, drop exporters + dedup + # state) before the primary emitter, so a late capture can't re-register work. + from src.llm.capture import clear_exporters + from src.telemetry import langfuse_session, trace_session + from src.telemetry.emitter import shutdown_emitter, shutdown_trace_emitter + + clear_exporters() + await shutdown_trace_emitter() + trace_session.reset() + langfuse_session.reset() await shutdown_emitter() logger.info("CloudEvents telemetry shutdown complete") diff --git a/src/telemetry/events/agent.py b/src/telemetry/events/agent.py index df771709..95145608 100644 --- a/src/telemetry/events/agent.py +++ b/src/telemetry/events/agent.py @@ -191,12 +191,18 @@ class AgentToolSummaryCreatedEvent(BaseEvent): """ _event_type: ClassVar[str] = "agent.tool.summary.created" - _schema_version: ClassVar[int] = 2 + _schema_version: ClassVar[int] = 3 _category: ClassVar[str] = "agent" - # Run identification (may be placeholder if not from an agentic loop) - run_id: str = Field(..., description="Nanoid for run correlation") - iteration: int = Field(..., description="Iteration number when this occurred") + # Run identification. + run_id: str | None = Field( + default=None, + description="Run id for agentic correlation; None when not in a run", + ) + iteration: int | None = Field( + default=None, + description="Iteration within an agentic loop; None when not in one", + ) # Context parent_category: str = Field(..., description="Parent category") @@ -258,8 +264,9 @@ class AgentToolSummaryCreatedEvent(BaseEvent): ) def get_resource_id(self) -> str: - """Resource ID includes run_id and iteration for uniqueness.""" - return f"{self.run_id}:{self.iteration}:summary_created" + """Idempotency key. A summary is unique per (message it covers up to, + tier)""" + return f"{self.message_id}:{self.summary_type}:summary_created" class AgentToolCallCompletedEvent(BaseEvent): diff --git a/src/telemetry/events/trace.py b/src/telemetry/events/trace.py new file mode 100644 index 00000000..37383bc0 --- /dev/null +++ b/src/telemetry/events/trace.py @@ -0,0 +1,161 @@ +"""Replay-grade payload events for full-fidelity LLM tracing. + +Two ground-truth (never-sampled) events that make the CloudEvents stream carry +the exact context a model saw, content-addressed to keep payload O(N): + +- ``LLMCallTracedEvent`` (``llm.call.traced``) — one per LLM call. Carries + span-tree correlation, path identity, content *references* (hashes, not bytes) + for the context window and the replay-grade output, plus a self-contained + accounting copy. It deliberately does NOT claim a join to + ``llm.call.completed`` — cost is computable from the trace alone, so the + billing and audit streams stay decoupled. +- ``TraceContentEvent`` (``trace.content``) — one per unique message, emitted + once per run and referenced by hash. ``content_hash`` covers the full message + identity ({role, content, tool_call_id}) so identical text under different + roles can't collide. ``generate_id()`` is overridden to derive the CloudEvent + id from the hash with NO timestamp, so accidental re-sends of identical + content dedupe at the transport layer too. +""" + +from __future__ import annotations + +from typing import Any, ClassVar + +from pydantic import Field + +from src.config import ModelTransport +from src.telemetry.events.base import BaseEvent + +__all__ = ["EmbeddingCallTracedEvent", "LLMCallTracedEvent", "TraceContentEvent"] + + +class LLMCallTracedEvent(BaseEvent): + """One replay-grade record per LLM call. Ground-truth, never sampled. + + Content fields are *references* (content hashes) into the ``trace.content`` + store, never inline bytes + """ + + _event_type: ClassVar[str] = "llm.call.traced" + _schema_version: ClassVar[int] = 1 + _category: ClassVar[str] = "trace" + _volume_class: ClassVar[str] = "ground_truth" + + # --- Correlation (span tree) --- + trace_id: str | None = None + span_id: str | None = None + parent_span_id: str | None = None + iteration: int | None = None + step_seq: int = 0 + attempt: int = 1 + was_fallback: bool = False + parent_event_id: str | None = None + + # --- Path identity --- + call_purpose: str | None = None + parent_category: str | None = None + # Used for grouping traces + session_id: str | None = None + transport: ModelTransport + provider_label: str | None = None + model: str + + # --- Context window (content-addressed) --- + input_message_refs: list[str] = Field(default_factory=list) + system_prompt_ref: str | None = None + tool_schema_refs: list[str] = Field(default_factory=list) + tool_choice: Any = None + + # --- Output (replay-grade) --- + output_content_ref: str | None = None + output_tool_calls: list[dict[str, Any]] = Field(default_factory=list) + output_thinking_ref: str | None = None + output_signatures: list[str] = Field(default_factory=list) + # Reserved: Honcho captures the normalized request/response, not wire bytes. + raw_response_ref: str | None = None + finish_reason: str | None = None + + # --- Accounting copy (stream stands alone; NOT joined to llm.call.completed) --- + provider_input_tokens: int = 0 + provider_output_tokens: int = 0 + cache_read_tokens: int = 0 + cache_creation_tokens: int = 0 + was_truncated: bool = False + + def get_resource_id(self) -> str: + """Idempotency key. ``tool_call_seq`` is deliberately absent — it indexed + tool *executions*, not LLM calls, and was never a valid join field.""" + return f"{self.span_id}:{self.iteration}:{self.attempt}:{self.step_seq}" + + +class EmbeddingCallTracedEvent(BaseEvent): + """One trace-stream record per embedding-provider call.""" + + _event_type: ClassVar[str] = "embedding.call.traced" + _schema_version: ClassVar[int] = 1 + _category: ClassVar[str] = "trace" + _volume_class: ClassVar[str] = "ground_truth" + + # --- Correlation (span tree) --- + trace_id: str | None = None + span_id: str | None = None + parent_span_id: str | None = None + iteration: int | None = None + step_seq: int = 0 + attempt: int = 1 + session_id: str | None = None + + # --- Path identity --- + call_purpose: str | None = None + parent_category: str | None = None + provider: str + model: str + + # --- Accounting copy --- + # v1: input tokens are a tiktoken ESTIMATE (no authoritative provider count is + # plumbed yet); output tokens are always 0 (embeddings produce none). + provider_input_tokens: int = 0 + provider_output_tokens: int = 0 + input_count: int = 0 + was_truncated: bool = False + + def get_resource_id(self) -> str: + return f"{self.span_id}:embedding:{self.call_purpose}:{self.input_count}" + + +class TraceContentEvent(BaseEvent): + """One unique message in the content store. Ground-truth, never sampled. + + The hash covers the full message identity, and the event id derives from the + hash with no timestamp. + """ + + _event_type: ClassVar[str] = "trace.content" + _schema_version: ClassVar[int] = 1 + _category: ClassVar[str] = "trace" + _volume_class: ClassVar[str] = "ground_truth" + + content_hash: str + role: str + # Message text, normalized across providers. + content: Any = None + tool_call_id: str | None = None + # Tool calls in a unified {id, name, input} shape (provider-agnostic). + tool_calls: list[dict[str, Any]] = Field(default_factory=list) + # Tags Honcho-authored content (system prompts, scaffold) so tenant-facing + # views can withhold globally-shared content (the §6.3 access invariant — + # dedup is global, the content store has no tenant column). + honcho_authored: bool = False + + def get_resource_id(self) -> str: + return self.content_hash + + def generate_id(self) -> str: + """Content-addressed id with NO timestamp/version. + + Overrides the base (which folds timestamp + honcho_version) so any + cross-process or cross-retry re-send of the same content collides on + the same id and dedupes at the transport layer. + """ + digest = self.content_hash.split(":", 1)[-1] + return f"content_{digest[:22]}" diff --git a/src/telemetry/langfuse_exporter.py b/src/telemetry/langfuse_exporter.py new file mode 100644 index 00000000..e66eb8ac --- /dev/null +++ b/src/telemetry/langfuse_exporter.py @@ -0,0 +1,398 @@ +"""Langfuse projection over the captured LLM trace stream. + +`LangfuseExporter` is an `LLMCallExporter`, active when +`LANGFUSE_EXPORTER_MODE == "exporter"`. It receives one `CapturedLLMCall` at a +time and rebuilds the Langfuse trace tree from the ids on each call, since there +is no live span nesting to inherit: + + Trace (id = create_trace_id(seed=honcho trace_id)) + └─ [dream root] (multi-specialist agents only — one "Dream" span per trace) + └─ run span (one per (run_id, agent_type); name = track_name) + └─ step span (one per (agent_type, iteration); name = " step") + ├─ generation (one per CapturedLLMCall; name = " generation") + └─ tool span (one per requested tool call; sibling of generation) + +Run and step spans are created once per trace and reused as the `parent_span_id` +of later calls (tracked in `langfuse_session`). Single-shot callers +(deriver/summarizer, `run_id is None`) skip the run/step wrappers and put the +generation at the trace root. + +The Dreamer runs two specialists (deduction + induction) under one run_id, so its +branches hang off a single synthetic "Dream" root to keep the trace +single-rooted; single-specialist agents (dialectic) let their run span be the +root. Keeping exactly one root is also why child spans are demoted from the SDK's +auto-root flag (see `_demote_from_root`). + +Best-effort throughout: every export is wrapped so telemetry can never break the +LLM call path. +""" + +from __future__ import annotations + +import logging +from typing import Any + +from src.config import settings +from src.llm.capture import CapturedLLMCall +from src.telemetry import langfuse_session + +logger = logging.getLogger(__name__) + +# finish_reason values that mark the generation as failed. +_ERROR_FINISHES = frozenset({"error", "cancelled"}) + + +class LangfuseExporter: + """`LLMCallExporter` that projects captured calls onto Langfuse traces.""" + + def export(self, call: CapturedLLMCall) -> None: + if not settings.langfuse_exporter_enabled: + return + try: + self._export(call) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug("Langfuse exporter failed", exc_info=True) + + def _export(self, call: CapturedLLMCall) -> None: + from langfuse import get_client + + client = get_client() + seed = call.trace_id or call.run_id or call.span_id + if not seed: + return + lf_trace_id = client.create_trace_id(seed=seed) + + # Agentic runs (run_id set: dialectic / dreamer) get a run span and + # per-iteration step spans; single-shot calls put the generation at root. + # Branch = agent_type so co-trace specialists (dreamer) don't collide. + parent_span_id: str | None = None + if call.run_id is not None: + branch = call.agent_type or "_" + # Multi-specialist agents (the Dreamer runs deduction + induction in + # ONE trace) hang every branch off a single synthetic trace root, so + # the trace has one root instead of one per specialist. That root + # also stamps the trace attrs. Single-specialist agents (dialectic) + # get None here and let their run span be the root. + root_span_id = self._ensure_trace_root(client, lf_trace_id, call) + run_span_id = langfuse_session.ensure_run_span( + lf_trace_id, + branch, + lambda should_stamp: self._create_span( + client, + lf_trace_id, + parent_span_id=root_span_id, + name=call.track_name or "LLM run", + metadata=self._metadata(call), + # The synthetic root stamps the trace attrs when present; + # otherwise the first branch's run span does. + stamp_trace=should_stamp and root_span_id is None, + call=call, + ), + ) + parent_span_id = run_span_id + if call.iteration is not None and run_span_id is not None: + parent_span_id = langfuse_session.ensure_step_span( + lf_trace_id, + branch, + call.iteration, + lambda: self._create_span( + client, + lf_trace_id, + parent_span_id=run_span_id, + name=self._step_name(call), + metadata=self._step_metadata(call), + stamp_trace=False, + call=call, + ), + ) + + self._create_generation( + client, + lf_trace_id, + parent_span_id=parent_span_id, + # Single-shot: the generation is the trace root, so it stamps the + # trace attrs. Agentic: the first branch's run span already did. + stamp_trace=call.run_id is None, + call=call, + ) + + # Tool calls the model requested this iteration: siblings of the + # generation under the step span. Skipped at the trace root (single-shot + # callers don't use tools) since there's no step to anchor them. + if parent_span_id is not None and call.output_tool_calls: + for seq, tool_call in enumerate(call.output_tool_calls): + self._create_tool_span( + client, lf_trace_id, parent_span_id, seq, tool_call, call + ) + + # -- observation builders ------------------------------------------------ + + def _ensure_trace_root( + self, client: Any, lf_trace_id: str, call: CapturedLLMCall + ) -> str | None: + """Single branch-agnostic trace root for multi-specialist agents. + + The Dreamer's deduction + induction specialists share one trace (same + run_id) but each builds its own run span with no parent — so Langfuse + sees two roots, races the trace name between them, and renders the + specialists as separate sub-traces. One synthetic "Dream" root (which + also stamps the trace attrs) gives the trace a single root with both + specialists nested beneath. Single-specialist agents (dialectic) return + None and let their run span be the root. + """ + if call.parent_category != "dream": + return None + return langfuse_session.ensure_trace_root( + lf_trace_id, + lambda: self._create_span( + client, + lf_trace_id, + parent_span_id=None, + name=self._trace_name(call) or "Dream", + metadata=self._root_metadata(call), + stamp_trace=True, + call=call, + ), + ) + + def _create_span( + self, + client: Any, + lf_trace_id: str, + *, + parent_span_id: str | None, + name: str, + metadata: dict[str, str], + stamp_trace: bool, + call: CapturedLLMCall, + ) -> str | None: + """Create a (run or step) span, returning its OTEL span id. + + Created-and-ended immediately: nesting is by id, so children link fine to + an already-ended parent. Span durations are therefore approximate — an + accepted v1 trade for not having a 'run finished' signal in the stream. + """ + obs = client.start_observation( + trace_context=self._trace_context(lf_trace_id, parent_span_id), + name=name, + as_type="span", + metadata=metadata, + ) + if stamp_trace: + self._stamp_trace_attrs(obs, call) + if parent_span_id is not None: + self._demote_from_root(obs) + obs.end() + return getattr(obs, "id", None) + + def _create_generation( + self, + client: Any, + lf_trace_id: str, + *, + parent_span_id: str | None, + stamp_trace: bool, + call: CapturedLLMCall, + ) -> None: + level = "ERROR" if (call.finish_reason in _ERROR_FINISHES) else None + obs = client.start_observation( + trace_context=self._trace_context(lf_trace_id, parent_span_id), + name=self._gen_name(call), + as_type="generation", + model=call.model, + input=self._input(call), + output=self._output(call), + metadata=self._step_metadata(call), + usage_details=self._usage(call), + level=level, + ) + if stamp_trace: + self._stamp_trace_attrs(obs, call) + if parent_span_id is not None: + self._demote_from_root(obs) + obs.end() + + def _create_tool_span( + self, + client: Any, + lf_trace_id: str, + parent_span_id: str, + seq: int, + tool_call: dict[str, Any], + call: CapturedLLMCall, + ) -> None: + """Create a tool span for one requested tool call, under the step span. + + Built from the model's request (`output_tool_calls`): tool name + input + args. Result/duration/error aren't on the captured call (they live on + AgentToolCallCompletedEvent) — a later enrichment, not v1. + """ + obs = client.start_observation( + trace_context=self._trace_context(lf_trace_id, parent_span_id), + name=str(tool_call.get("name") or "tool"), + as_type="tool", + input=tool_call.get("input"), + metadata=self._tool_metadata(call, seq), + ) + self._demote_from_root(obs) # always a child of the step span + obs.end() + + @staticmethod + def _demote_from_root(obs: Any) -> None: + """Clear the AS_ROOT flag the SDK auto-stamps on a child observation. + + `start_observation(trace_context={"trace_id": ...})` marks EVERY span it + mints with `AS_ROOT=True` (langfuse `_client/client.py`) — including the + step/generation/tool spans we link under a run span by id. With several + root-flagged spans in one trace, Langfuse resolves the trace's root (and + therefore its name) from whichever it ingests first: a race that names a + dialectic trace after a child ("... step"/"... generation") and renders + children as if each were its own trace. Demoting every span that has a + real parent leaves exactly one root, making name + nesting deterministic. + Verified empirically against Langfuse cloud (the dangling remote-parent + id on the surviving root is benign and unavoidable — it's present even + with native context nesting). + """ + span = getattr(obs, "_otel_span", None) + if span is None: + return + from langfuse import LangfuseOtelSpanAttributes as Attr + + span.set_attribute(Attr.AS_ROOT, False) + + @staticmethod + def _trace_context(lf_trace_id: str, parent_span_id: str | None) -> dict[str, str]: + ctx: dict[str, str] = {"trace_id": lf_trace_id} + if parent_span_id is not None: + ctx["parent_span_id"] = parent_span_id + return ctx + + def _stamp_trace_attrs(self, obs: Any, call: CapturedLLMCall) -> None: + """Stamp user/name on the trace via the root observation's span. + + Called once per trace, on the first branch's run span (decided by + `langfuse_session.ensure_run_span`) or, for single-shot calls, on the + generation (its own trace). + + Deliberately does NOT set a Langfuse session: no Honcho construct is a + conversation thread. A dialectic chat is a one-shot query scoped to a + session, not a turn in a multi-turn dialectic exchange (no such primitive + exists), so grouping independent queries under one Langfuse session would + invent a conversation that isn't there. The Honcho session rides in + metadata (`honcho_session`) instead — a correlation key, not a group.""" + span = getattr(obs, "_otel_span", None) + if span is None: + return + from langfuse import LangfuseOtelSpanAttributes as Attr + + span.set_attribute(Attr.TRACE_USER_ID, str(settings.NAMESPACE)) + trace_name = self._trace_name(call) + if trace_name: + span.set_attribute(Attr.TRACE_NAME, trace_name) + + # -- field mappers (port of runtime._base_metadata/_step_metadata) ------- + + @staticmethod + def _metadata(call: CapturedLLMCall) -> dict[str, str]: + # `trace_id` is the run grouping key (also handy for cross-referencing the + # CloudEvents stream). `span_id`/`parent_span_id` are intentionally omitted + # until the source mints distinct per-call span ids: today every call in a + # run shares span_id == trace_id == run_id, so surfacing them here only + # duplicates trace_id and misleads. Re-add once the source differentiates. + md: dict[str, str] = {"namespace": str(settings.NAMESPACE)} + for key, value in ( + ("workspace_name", call.workspace_name), + ("call_purpose", call.call_purpose), + ("agent_type", call.agent_type), + ("observer", call.observer), + ("observed", call.observed), + ("peer_name", call.peer_name), + ("trace_id", call.trace_id), + # Honcho session as a correlation key, NOT a Langfuse session — see + # `_stamp_trace_attrs`. Lets you filter "queries scoped to session X" + # without falsely grouping one-shot dialectic queries as a thread. + ("honcho_session", call.session_id), + ): + if value is not None: + md[key] = str(value) + return md + + @staticmethod + def _root_metadata(call: CapturedLLMCall) -> dict[str, str]: + # Branch-agnostic: the synthetic dream root spans both specialists, so it + # carries only trace-level fields — not a single specialist's agent_type/ + # observer/observed/call_purpose. + md: dict[str, str] = {"namespace": str(settings.NAMESPACE)} + for key, value in ( + ("workspace_name", call.workspace_name), + ("trace_id", call.trace_id), + ): + if value is not None: + md[key] = str(value) + return md + + def _step_metadata(self, call: CapturedLLMCall) -> dict[str, str]: + md = self._metadata(call) + if call.iteration is not None: + md["iteration"] = str(call.iteration) + md["step_seq"] = str(call.step_seq) + md["attempt"] = str(call.attempt) + md["provider"] = str(call.transport) + md["model"] = str(call.model) + return md + + def _tool_metadata(self, call: CapturedLLMCall, seq: int) -> dict[str, str]: + md = self._step_metadata(call) + md["tool_call_seq"] = str(seq) + return md + + @staticmethod + def _trace_name(call: CapturedLLMCall) -> str | None: + # Branch-agnostic trace label: the Dreamer's two specialists share one + # trace, so the trace name must not be pinned to whichever specialist's + # run span stamped it first. Per-branch identity stays on the run spans. + if call.parent_category == "dream": + return "Dream" + return call.track_name + + @staticmethod + def _step_name(call: CapturedLLMCall) -> str: + # Canonical, index-free name: Langfuse aggregates step spans by name and + # the iteration/step_seq/attempt ride on metadata (see _step_metadata). + return f"{call.track_name} step" if call.track_name else "Agent step" + + @staticmethod + def _gen_name(call: CapturedLLMCall) -> str: + return f"{call.track_name} generation" if call.track_name else "generation" + + @staticmethod + def _input(call: CapturedLLMCall) -> list[dict[str, Any]]: + out: list[dict[str, Any]] = [] + for message in call.input_messages: + entry: dict[str, Any] = {"role": message.role, "content": message.content} + if message.tool_call_id is not None: + entry["tool_call_id"] = message.tool_call_id + if message.tool_calls: + entry["tool_calls"] = message.tool_calls + out.append(entry) + return out + + @staticmethod + def _output(call: CapturedLLMCall) -> Any: + if isinstance(call.output_content, str) and call.output_content.strip(): + return call.output_content + if call.output_tool_calls: + return {"tool_calls": [tc.get("name") for tc in call.output_tool_calls]} + return call.output_content + + @staticmethod + def _usage(call: CapturedLLMCall) -> dict[str, int]: + return { + "input": call.input_tokens, + "output": call.output_tokens, + "cache_read_input_tokens": call.cache_read_tokens, + "cache_creation_input_tokens": call.cache_creation_tokens, + } + + +__all__ = ["LangfuseExporter"] diff --git a/src/telemetry/langfuse_session.py b/src/telemetry/langfuse_session.py new file mode 100644 index 00000000..3dc2c13e --- /dev/null +++ b/src/telemetry/langfuse_session.py @@ -0,0 +1,122 @@ +"""Per-trace span registry backing the `LangfuseExporter`. + +The exporter sees one `CapturedLLMCall` at a time, but a single agentic run fans +out into many calls that must nest under one run span with per-iteration step +spans. Langfuse links observations by OTEL span id, and each id is minted fresh +and unpredictable — so this module remembers the run/step span ids created for a +trace and hands them back as the `parent_span_id` of later calls. + +Spans are keyed per branch (the `agent_type`) within a trace. The Dreamer's +deduction and induction specialists share one trace but are separate sub-trees; +without the branch key their iterations and generations would collide. + +Per trace, it holds each branch's run span id, the per-(branch, iteration) step +span ids, and whether trace-level attrs have been stamped — so each is created +once. The stamp decision is made inside `ensure_run_span` under the lock so it +can't double-fire across branches. + +Bounded by an LRU over traces (`_MAX_TRACES`), lock-guarded, best-effort. +""" + +from __future__ import annotations + +import logging +import threading +from collections import OrderedDict +from collections.abc import Callable +from dataclasses import dataclass, field + +logger = logging.getLogger(__name__) + +# LRU window / runaway backstop — far more than the traces ever live at once; the +# least-recently-used trace is evicted past this. Not a tuning knob. +_MAX_TRACES = 4096 + + +@dataclass +class _TraceState: + root_span_id: str | None = None # synthetic trace root (multi-specialist agents) + run_span_ids: dict[str, str] = field(default_factory=dict) # branch -> span id + step_span_ids: dict[tuple[str, int], str] = field( + default_factory=dict + ) # (branch, iteration) -> span id + attrs_stamped: bool = False + + +_traces: OrderedDict[str, _TraceState] = OrderedDict() +_lock = threading.Lock() + + +def _get_or_create_state(trace_key: str) -> _TraceState: + """Return the `_TraceState` for `trace_key`, creating it if new and marking it + most-recently-used. Caller MUST hold `_lock`. Bounded by an LRU: a new trace + past `_MAX_TRACES` evicts the least-recently-used (almost always finished) one. + """ + state = _traces.get(trace_key) + if state is None: + if len(_traces) >= _MAX_TRACES: + _traces.popitem(last=False) # evict the least-recently-used trace + state = _traces[trace_key] = _TraceState() + else: + _traces.move_to_end(trace_key) # mark most-recently-used + return state + + +def ensure_trace_root(trace_key: str, create: Callable[[], str | None]) -> str | None: + """Return the single trace-root span id for `trace_key`, creating it once. + + Used by multi-specialist agents (the Dreamer) whose branches share one trace + but must all hang off ONE root span. Single-specialist agents don't call + this. Mirrors `ensure_run_span`'s retry-on-None: a failed create just yields + None (the caller then roots the branch directly) and is retried next call. + """ + with _lock: + state = _get_or_create_state(trace_key) + if state.root_span_id is None: + state.root_span_id = create() + return state.root_span_id + + +def ensure_run_span( + trace_key: str, branch: str, create: Callable[[bool], str | None] +) -> str | None: + """Return the run span id for `(trace_key, branch)`, creating it once. + + `create` receives `should_stamp` — True exactly once per trace, on the first + branch's run span — and builds the Langfuse run span (stamping trace-level + attrs iff asked), returning its span id (or None on failure). The stamp + decision is computed here, under the lock, so it can't double-fire across the + Dreamer's two specialist branches; `create` must not re-enter this module. + """ + with _lock: + state = _get_or_create_state(trace_key) + existing = state.run_span_ids.get(branch) + if existing is None: + should_stamp = not state.attrs_stamped + existing = create(should_stamp) + if existing is not None: + state.run_span_ids[branch] = existing + if should_stamp: + state.attrs_stamped = True + return existing + + +def ensure_step_span( + trace_key: str, branch: str, iteration: int, create: Callable[[], str | None] +) -> str | None: + """Return the step span id for `(trace_key, branch, iteration)`, creating once.""" + with _lock: + state = _get_or_create_state(trace_key) + key = (branch, iteration) + existing = state.step_span_ids.get(key) + if existing is None: + existing = create() + if existing is not None: + state.step_span_ids[key] = existing + return existing + + +def reset() -> None: + """Drop all tracked traces — used on shutdown and in tests.""" + with _lock: + _traces.clear() diff --git a/src/telemetry/logging.py b/src/telemetry/logging.py index b653952e..9c5f6648 100644 --- a/src/telemetry/logging.py +++ b/src/telemetry/logging.py @@ -75,7 +75,11 @@ def conditional_observe( capture_output: bool | None = None, ) -> Callable[P, R] | Callable[[Callable[P, R]], Callable[P, R]]: """ - Conditionally apply the @observe decorator only when LANGFUSE_PUBLIC_KEY is present. + Conditionally apply the @observe decorator only in legacy inline mode + (``langfuse_inline_enabled`` — i.e. a key is set AND + ``LANGFUSE_EXPORTER_MODE == "inline"``). In exporter mode the LangfuseExporter + rebuilds every observation from the captured trace stream, so a live + @observe span here would double-emit. Can be used in two ways: 1. As a decorator: @conditional_observe @@ -105,7 +109,10 @@ def conditional_observe( """ def decorator(f: Callable[P, R]) -> Callable[P, R]: - if not settings.LANGFUSE_PUBLIC_KEY: + # Only auto-instrument with @observe in legacy inline mode. In exporter + # mode the LangfuseExporter produces every observation from the captured + # trace stream, so a live @observe span here would double-emit. + if not settings.langfuse_inline_enabled: return f # `observe` treats None as "use SDK default", so passing the optionals # straight through is equivalent to omitting them. diff --git a/src/telemetry/trace_exporter.py b/src/telemetry/trace_exporter.py new file mode 100644 index 00000000..0023f97a --- /dev/null +++ b/src/telemetry/trace_exporter.py @@ -0,0 +1,169 @@ +"""CloudEvents exporter: turns a CapturedLLMCall into trace events. + +Registered into the `src/llm/capture.py` exporter registry at startup when +`TELEMETRY.TRACE_PAYLOADS_ENABLED` is on. For each captured call it emits: +- one `trace.content` per unique message/output/thinking/tool-schema (deduped + per run so each ships once), and +- one `llm.call.traced` carrying the span-tree correlation + content refs + + a self-contained accounting copy. +""" + +from __future__ import annotations + +import logging +from typing import Any + +from src.config import settings +from src.llm.capture import ( + ROLE_OUTPUT, + ROLE_THINKING, + ROLE_TOOL_SCHEMA, + CapturedLLMCall, + clip_for_trace, + compute_content_hash, +) +from src.telemetry import trace_session +from src.telemetry.events import emit_trace +from src.telemetry.events.trace import LLMCallTracedEvent, TraceContentEvent + +logger = logging.getLogger(__name__) + + +class TraceExporter: + """`LLMCallExporter` that ships replay-grade content to the trace stream.""" + + def export(self, call: CapturedLLMCall) -> None: + # Double-gate (the exporter is only registered when on, but a config + # flip or a stray registration shouldn't leak payloads). + if not settings.TELEMETRY.TRACE_PAYLOADS_ENABLED: + return + purposes = settings.TELEMETRY.TRACE_PURPOSES + if purposes and call.call_purpose not in purposes: + return + + run_key = call.trace_id or call.span_id or call.run_id or "" + was_truncated = call.input_truncated + + # --- Context window: reuse precomputed input-message hashes --- + input_message_refs: list[str] = [] + for message in call.input_messages: + input_message_refs.append(message.content_hash) + self._emit_content( + run_key, + content_hash=message.content_hash, + role=message.role, + content=message.content, + tool_call_id=message.tool_call_id, + honcho_authored=message.role == "system", + tool_calls=message.tool_calls, + ) + + # --- Tool schemas (Honcho-authored, content-addressed) --- + tool_schema_refs: list[str] = [] + for schema in call.tool_schemas: + ref, truncated = self._emit_hashed_content( + run_key, ROLE_TOOL_SCHEMA, schema, honcho_authored=True + ) + was_truncated = was_truncated or truncated + tool_schema_refs.append(ref) + + # --- Output content / thinking --- + output_content_ref: str | None = None + if call.output_content not in (None, ""): + output_content_ref, truncated = self._emit_hashed_content( + run_key, ROLE_OUTPUT, call.output_content + ) + was_truncated = was_truncated or truncated + + output_thinking_ref: str | None = None + if call.thinking_content: + output_thinking_ref, truncated = self._emit_hashed_content( + run_key, ROLE_THINKING, call.thinking_content + ) + was_truncated = was_truncated or truncated + + signatures = [ + block["signature"] + for block in call.thinking_blocks + if block.get("signature") + ] + + emit_trace( + LLMCallTracedEvent( + trace_id=call.trace_id, + span_id=call.span_id, + parent_span_id=call.parent_span_id, + iteration=call.iteration, + step_seq=call.step_seq, + attempt=call.attempt, + was_fallback=call.was_fallback, + call_purpose=call.call_purpose, + parent_category=call.parent_category, + session_id=call.session_id, + transport=call.transport, # pyright: ignore[reportArgumentType] + provider_label=call.provider_label, + model=call.model, + input_message_refs=input_message_refs, + tool_schema_refs=tool_schema_refs, + tool_choice=call.tool_choice, + output_content_ref=output_content_ref, + output_tool_calls=call.output_tool_calls, + output_thinking_ref=output_thinking_ref, + output_signatures=signatures, + finish_reason=call.finish_reason, + provider_input_tokens=call.input_tokens, + provider_output_tokens=call.output_tokens, + cache_read_tokens=call.cache_read_tokens, + cache_creation_tokens=call.cache_creation_tokens, + was_truncated=was_truncated, + ) + ) + + def _emit_hashed_content( + self, + run_key: str, + role: str, + raw_content: Any, + *, + honcho_authored: bool = False, + ) -> tuple[str, bool]: + """Clip + hash a non-message content value and emit it. Returns (hash, truncated).""" + content, truncated = clip_for_trace(raw_content) + content_hash = compute_content_hash(role, content, None) + self._emit_content( + run_key, + content_hash=content_hash, + role=role, + content=content, + tool_call_id=None, + honcho_authored=honcho_authored, + ) + return content_hash, truncated + + def _emit_content( + self, + run_key: str, + *, + content_hash: str, + role: str, + content: Any, + tool_call_id: str | None, + honcho_authored: bool, + tool_calls: list[dict[str, Any]] | None = None, + ) -> None: + """Emit one trace.content, deduped per run (skip if already shipped).""" + if not trace_session.mark_emitted(run_key, content_hash): + return + emit_trace( + TraceContentEvent( + content_hash=content_hash, + role=role, + content=content, + tool_call_id=tool_call_id, + honcho_authored=honcho_authored, + tool_calls=tool_calls or [], + ) + ) + + +__all__ = ["TraceExporter"] diff --git a/src/telemetry/trace_session.py b/src/telemetry/trace_session.py new file mode 100644 index 00000000..a08ca9d7 --- /dev/null +++ b/src/telemetry/trace_session.py @@ -0,0 +1,73 @@ +"""Per-run content dedup for the trace stream — makes bandwidth O(N). + +Tracks the set of content hashes a run has already shipped, so each unique +message ships its `trace.content` exactly once per run. + +The set is bounded by an LRU over runs: once more than `_MAX_RUNS` runs are +tracked, the least-recently-touched one is evicted (almost always a run that has +already finished), so dedup keeps working for active runs no matter how many the +process has handled. A single run exceeding `_MAX_HASHES_PER_RUN` unique messages +stops deduping and emits-anyway, bumping a metric — that loss is measured. +""" + +from __future__ import annotations + +import logging +import threading +from collections import OrderedDict + +logger = logging.getLogger(__name__) + +# LRU window over runs + per-run hash cap. Generous — a run rarely has more than +# a few hundred unique messages, and far fewer than _MAX_RUNS are ever live at +# once; both are runaway backstops, not tuning knobs. +_MAX_RUNS = 4096 +_MAX_HASHES_PER_RUN = 8192 + +# trace_id (fallback span_id) → set of content hashes already shipped this run. +# OrderedDict so we can evict the least-recently-used run when over _MAX_RUNS. +_runs: OrderedDict[str, set[str]] = OrderedDict() +_lock = threading.Lock() + + +def mark_emitted(run_key: str, content_hash: str) -> bool: + """Return True if this hash should be shipped for ``run_key`` (first time), + False if already shipped this run (skip the ``trace.content``). + + A run exceeding `_MAX_HASHES_PER_RUN` returns True (emit-anyway) and records a + drop of the dedup *guarantee* — the event still ships, we just stopped + tracking. Tracking a new run past `_MAX_RUNS` evicts the LRU run instead (a + routine, lossless bound — the evicted run is almost always already finished). + """ + with _lock: + seen = _runs.get(run_key) + if seen is None: + if len(_runs) >= _MAX_RUNS: + _runs.popitem(last=False) # evict the least-recently-used run + seen = _runs[run_key] = set() + else: + _runs.move_to_end(run_key) # mark most-recently-used + if content_hash in seen: + return False + if len(seen) >= _MAX_HASHES_PER_RUN: + _record_overflow("max_hashes") + return True + seen.add(content_hash) + return True + + +def reset() -> None: + """Drop all tracked runs — used on shutdown and in tests.""" + with _lock: + _runs.clear() + + +def _record_overflow(reason: str) -> None: + try: + from src.telemetry import prometheus_metrics + + prometheus_metrics.record_telemetry_event_dropped( + reason=f"trace_dedup_{reason}" + ) + except Exception: # pragma: no cover - best-effort telemetry + logger.debug("trace dedup overflow (%s)", reason) diff --git a/src/utils/agent_tools.py b/src/utils/agent_tools.py index bac3948a..d4df768b 100644 --- a/src/utils/agent_tools.py +++ b/src/utils/agent_tools.py @@ -2523,8 +2523,13 @@ def _begin_tool_observation(tool_name: str, tool_input: dict[str, Any]) -> Any: Auto-parents under the active step span (else standalone). Returns a handle (closed by `_finish_tool_observation`) or None when disabled/setup fails. All tools are ``as_type="tool"`` — they share one generic dispatcher. + + Only fires in legacy *inline* mode. In exporter mode there's no live span + context to parent under, so this would emit a rootless tool trace per call; + the LangfuseExporter already projects tool spans (from ``output_tool_calls``) + nested under the step span, so a live observation here just double-emits. """ - if not settings.LANGFUSE_PUBLIC_KEY: + if not settings.langfuse_inline_enabled: return None try: from langfuse import get_client diff --git a/src/utils/summarizer.py b/src/utils/summarizer.py index 42d18bcc..2abdb0f9 100644 --- a/src/utils/summarizer.py +++ b/src/utils/summarizer.py @@ -6,6 +6,7 @@ from functools import cache from inspect import cleandoc as c from typing import TypedDict +from nanoid import generate as generate_nanoid from sqlalchemy import update from sqlalchemy.ext.asyncio import AsyncSession @@ -219,6 +220,9 @@ async def create_short_summary( formatted_messages, output_words, previous_summary_text ) + # Mint a root span id. + # No session_id or run_id for tracing + trace_id = generate_nanoid() return await honcho_llm_call( model_config=_get_summary_model_config(), prompt=prompt, @@ -227,6 +231,9 @@ async def create_short_summary( workspace_name=workspace_name, call_purpose=CallPurpose.SUMMARY_SHORT.value, parent_category="summary", + trace_id=trace_id, + span_id=trace_id, + track_name="Short Summary", ), ) @@ -251,6 +258,9 @@ async def create_long_summary( formatted_messages, output_words, previous_summary_text ) + # Mint a root span id. + # No session_id or run_id for tracing + trace_id = generate_nanoid() return await honcho_llm_call( model_config=_get_summary_model_config(), prompt=prompt, @@ -259,6 +269,9 @@ async def create_long_summary( workspace_name=workspace_name, call_purpose=CallPurpose.SUMMARY_LONG.value, parent_category="summary", + trace_id=trace_id, + span_id=trace_id, + track_name="Long Summary", ), ) @@ -514,17 +527,13 @@ async def _create_and_save_summary( "ms", ) - # Emit telemetry event (only for non-fallback summaries) - # Note: Using AgentToolSummaryCreatedEvent with dummy run_id/iteration since - # this is called from the deriver, not from an agentic loop + # Emit telemetry event (only for non-fallback summaries). if not is_fallback: # `prompt_tokens` is set in the `if not is_fallback` block above for # both SHORT and LONG summary types — we're inside the same branch, so # it's guaranteed bound here. emit( AgentToolSummaryCreatedEvent( - run_id="deriver", # Placeholder - not from an agentic run - iteration=0, # Placeholder - not from an agentic loop parent_category="deriver", agent_type="summarizer", workspace_name=workspace_name, diff --git a/src/utils/types.py b/src/utils/types.py index 2a470d20..33a2993d 100644 --- a/src/utils/types.py +++ b/src/utils/types.py @@ -114,6 +114,12 @@ _embedding_run_id: ContextVar[str | None] = ContextVar("embedding_run_id", defau _embedding_parent_category: ContextVar[str | None] = ContextVar( "embedding_parent_category", default=None ) +# Honcho Session.id for the embedding's trace grouping (e.g. a dialectic +# prefetch embedding shares the dialectic invocation's session). None when the +# embedding isn't scoped to a session. +_embedding_session_id: ContextVar[str | None] = ContextVar( + "embedding_session_id", default=None +) def get_embedding_call_purpose() -> str | None: @@ -136,6 +142,11 @@ def get_embedding_parent_category() -> str | None: return _embedding_parent_category.get() +def get_embedding_session_id() -> str | None: + """Read the Honcho Session.id attached to the current embedding call scope.""" + return _embedding_session_id.get() + + @contextmanager def embedding_call_purpose( purpose: str, @@ -143,6 +154,7 @@ def embedding_call_purpose( workspace_name: str | None = None, run_id: str | None = None, parent_category: str | None = None, + session_id: str | None = None, ) -> Generator[None]: """Tag any embedding calls made inside this `with` block. @@ -172,6 +184,9 @@ def embedding_call_purpose( if parent_category is not None else None ) + session_id_token = ( + _embedding_session_id.set(session_id) if session_id is not None else None + ) try: yield finally: @@ -182,6 +197,8 @@ def embedding_call_purpose( _embedding_run_id.reset(run_id_token) if parent_category_token is not None: _embedding_parent_category.reset(parent_category_token) + if session_id_token is not None: + _embedding_session_id.reset(session_id_token) @dataclass diff --git a/tests/llm/test_capture.py b/tests/llm/test_capture.py new file mode 100644 index 00000000..7dc22e95 --- /dev/null +++ b/tests/llm/test_capture.py @@ -0,0 +1,488 @@ +"""Tests for the single-capture content layer (src/llm/capture.py).""" + +from __future__ import annotations + +from collections.abc import AsyncIterator + +import pytest + +from src.llm import capture +from src.llm.backend import CompletionResult, ToolCallResult +from src.llm.capture import ( + CapturedLLMCall, + build_captured_call, + build_captured_messages, + canonical_json, + clip_for_trace, + compute_content_hash, +) +from src.llm.types import ( + HonchoLLMCallStreamChunk, + LLMTelemetryContext, + StreamingResponseWithMetadata, +) + + +async def _chunks( + texts: list[str], *, raise_after: BaseException | None = None +) -> AsyncIterator[HonchoLLMCallStreamChunk]: + for text in texts: + yield HonchoLLMCallStreamChunk(content=text) + if raise_after is not None: + raise raise_after + + +def _wrapper( + stream: AsyncIterator[HonchoLLMCallStreamChunk], + recorder: list[tuple[str, str]], +): + return StreamingResponseWithMetadata( + stream=stream, + tool_calls_made=[], + input_tokens=0, + output_tokens=0, + cache_creation_input_tokens=0, + cache_read_input_tokens=0, + capture_finalizer=lambda text, reason: recorder.append((text, reason)), + ) + + +class TestStreamingCaptureFinalizer: + async def test_clean_drain_captures_stop(self): + recorded: list[tuple[str, str]] = [] + wrapper = _wrapper(_chunks(["hel", "lo"]), recorded) + async for _ in wrapper: + pass + assert recorded == [("hello", "stop")] + + async def test_error_drain_captures_error_and_partial_text(self): + recorded: list[tuple[str, str]] = [] + wrapper = _wrapper(_chunks(["par"], raise_after=RuntimeError("boom")), recorded) + with pytest.raises(RuntimeError): + async for _ in wrapper: + pass + # Partial text still captured, tagged error. + assert recorded == [("par", "error")] + + async def test_cancelled_drain_captures_cancelled(self): + import asyncio + + recorded: list[tuple[str, str]] = [] + wrapper = _wrapper( + _chunks(["x"], raise_after=asyncio.CancelledError()), recorded + ) + with pytest.raises(asyncio.CancelledError): + async for _ in wrapper: + pass + assert recorded == [("x", "cancelled")] + + +class TestContentHash: + def test_is_deterministic_and_prefixed(self): + h1 = compute_content_hash("user", "hello", None) + h2 = compute_content_hash("user", "hello", None) + assert h1 == h2 + assert h1.startswith("sha256:") + + def test_role_is_inside_the_hash(self): + # Identical text under different roles must never collide — role lives + # inside the hash, closing the role-in-hash collision bug. + assert compute_content_hash("user", "hi", None) != compute_content_hash( + "assistant", "hi", None + ) + + def test_tool_call_id_is_inside_the_hash(self): + assert compute_content_hash("tool", "ok", "call_1") != compute_content_hash( + "tool", "ok", "call_2" + ) + + def test_canonical_json_is_order_independent(self): + assert canonical_json({"a": 1, "b": 2}) == canonical_json({"b": 2, "a": 1}) + + +class TestClipForTrace: + def test_leaves_small_content_untouched(self): + content, truncated = clip_for_trace("short") + assert content == "short" + assert truncated is False + + def test_clips_oversized_string(self, monkeypatch: pytest.MonkeyPatch): + from src.config import settings + + monkeypatch.setattr(settings.TELEMETRY, "TRACE_MAX_BYTES", 32) + content, truncated = clip_for_trace("x" * 1000) + assert truncated is True + assert content.endswith("…[truncated]") + assert len(content.encode("utf-8")) <= settings.TELEMETRY.TRACE_MAX_BYTES + + def test_leaves_structured_content_intact(self, monkeypatch: pytest.MonkeyPatch): + from src.config import settings + + monkeypatch.setattr(settings.TELEMETRY, "TRACE_MAX_BYTES", 4) + blocks = [{"type": "text", "text": "a long block of structured content"}] + content, truncated = clip_for_trace(blocks) + assert content == blocks + assert truncated is False + + +class TestBuildCapturedMessages: + def test_hashes_each_message(self): + messages = [ + {"role": "user", "content": "q"}, + {"role": "assistant", "content": "a"}, + ] + captured, truncated = build_captured_messages(messages, memo=None) + assert [m.role for m in captured] == ["user", "assistant"] + assert all(m.content_hash.startswith("sha256:") for m in captured) + assert truncated is False + + def test_memo_makes_hashing_on(self, monkeypatch: pytest.MonkeyPatch): + # The conversation is append-only and message dicts are reused, so with + # a shared memo each message is hashed exactly once across iterations. + calls = {"n": 0} + real = compute_content_hash + + def counting( + role: str, + content: object, + tool_call_id: str | None, + tool_calls: list[dict[str, object]] | None = None, + ) -> str: + calls["n"] += 1 + return real(role, content, tool_call_id, tool_calls) + + monkeypatch.setattr(capture, "compute_content_hash", counting) + + m1 = {"role": "user", "content": "q1"} + m2 = {"role": "assistant", "content": "a1"} + m3 = {"role": "user", "content": "q2"} + memo: dict[int, capture.CapturedMessage] = {} + + build_captured_messages([m1, m2], memo) + assert calls["n"] == 2 # both hashed + build_captured_messages([m1, m2, m3], memo) + assert calls["n"] == 3 # only the newly-appended m3 hashed (not re-hashed) + + +class TestNormalizeToolCalls: + """Tool calls live outside `content` for openai/gemini — capture must lift + them into the unified `tool_calls` shape (the PR concern).""" + + def test_openai_assistant_tool_calls_captured(self): + msg = { + "role": "assistant", + "content": None, + "tool_calls": [ + { + "id": "call_1", + "type": "function", + "function": { + "name": "search_memory", + "arguments": '{"query": "coffee"}', + }, + } + ], + } + captured, _ = build_captured_messages([msg], memo=None, transport="openai") + assert captured[0].tool_calls == [ + {"id": "call_1", "name": "search_memory", "input": {"query": "coffee"}} + ] + + def test_gemini_model_parts_captured(self): + msg = { + "role": "model", + "parts": [ + {"text": "let me look"}, + {"function_call": {"name": "grep_messages", "args": {"text": "x"}}}, + ], + } + captured, _ = build_captured_messages([msg], memo=None, transport="gemini") + assert captured[0].content == "let me look" + assert captured[0].tool_calls == [ + {"id": None, "name": "grep_messages", "input": {"text": "x"}} + ] + + def test_gemini_tool_result_recovered(self): + # Gemini tool results live in `parts` (no `content` key) and were dropped. + msg = { + "role": "user", + "parts": [ + { + "function_response": { + "name": "grep_messages", + "response": {"result": "3 hits"}, + } + } + ], + } + captured, _ = build_captured_messages([msg], memo=None, transport="gemini") + assert captured[0].content == "3 hits" + assert captured[0].tool_call_id == "grep_messages" + + def test_anthropic_tool_use_blocks_normalized(self): + msg = { + "role": "assistant", + "content": [ + {"type": "text", "text": "searching"}, + { + "type": "tool_use", + "id": "tu_1", + "name": "search_memory", + "input": {"q": "x"}, + }, + ], + } + captured, _ = build_captured_messages([msg], memo=None, transport="anthropic") + assert captured[0].content == "searching" + assert captured[0].tool_calls == [ + {"id": "tu_1", "name": "search_memory", "input": {"q": "x"}} + ] + + def test_hash_distinguishes_tool_calls(self): + # Two empty-content assistant turns with different tool calls must not + # collide in the dedup store (they did before tool_calls entered the hash). + base = {"role": "assistant", "content": None} + a = { + **base, + "tool_calls": [ + { + "id": "c1", + "type": "function", + "function": {"name": "search_memory", "arguments": "{}"}, + } + ], + } + b = { + **base, + "tool_calls": [ + { + "id": "c2", + "type": "function", + "function": {"name": "search_messages", "arguments": "{}"}, + } + ], + } + (ca,), _ = build_captured_messages([a], memo=None, transport="openai") + (cb,), _ = build_captured_messages([b], memo=None, transport="openai") + assert ca.content_hash != cb.content_hash + + +class TestBuildCapturedCall: + def test_maps_telemetry_and_result(self): + telemetry = LLMTelemetryContext( + workspace_name="ws", + call_purpose="dialectic.answer", + parent_category="dialectic", + run_id="r1", + trace_id="r1", + span_id="r1", + session_id="sess_abc", + iteration=2, + step_seq=2, + ) + result = CompletionResult( + content="answer", + input_tokens=10, + output_tokens=5, + finish_reason="stop", + tool_calls=[ToolCallResult(id="t1", name="search", input={"q": "x"})], + ) + call = build_captured_call( + telemetry=telemetry, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=result, + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + assert isinstance(call, CapturedLLMCall) + assert call.trace_id == "r1" and call.span_id == "r1" + assert call.iteration == 2 and call.step_seq == 2 + assert call.output_content == "answer" + assert call.output_tool_calls == [ + {"id": "t1", "name": "search", "input": {"q": "x"}} + ] + assert call.input_tokens == 10 and call.output_tokens == 5 + assert call.session_id == "sess_abc" + assert len(call.input_messages) == 1 + assert call.input_messages[0].content_hash.startswith("sha256:") + + def test_session_id_defaults_none_without_telemetry(self): + # Sessionless calls (and the no-telemetry path) carry session_id=None so + # the Langfuse projection emits no session grouping for them. + telemetry = LLMTelemetryContext(run_id="r1", trace_id="r1", span_id="r1") + call = build_captured_call( + telemetry=telemetry, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=CompletionResult(content="a", finish_reason="stop"), + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + assert call.session_id is None + + def test_self_parent_is_normalized_to_none(self): + # The tool loop sets parent_span_id == span_id on the run span (it + # doubles as the Langfuse "inside a run" signal). A span that is its own + # parent is a root, so the EXPORTED parent_span_id must be None — else + # span-tree consumers file the root as a child of itself. + telemetry = LLMTelemetryContext( + run_id="r1", trace_id="r1", span_id="r1", parent_span_id="r1" + ) + call = build_captured_call( + telemetry=telemetry, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=CompletionResult(content="a", finish_reason="stop"), + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + assert call.span_id == "r1" + assert call.parent_span_id is None + # A genuine distinct parent is preserved. + telemetry.parent_span_id = "parent-span" + assert telemetry.exported_parent_span_id() == "parent-span" + + def test_error_path_collapses_output(self): + call = build_captured_call( + telemetry=None, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=None, + attempt=2, + was_fallback=True, + was_stream=False, + finish_reason="error", + ) + assert call.output_content is None + assert call.output_tool_calls == [] + assert call.finish_reason == "error" + assert call.attempt == 2 and call.was_fallback is True + + +class TestExporterRegistry: + def test_register_dispatch_and_clear(self): + capture.clear_exporters() + assert capture.has_exporters() is False + seen: list[CapturedLLMCall] = [] + + class _Spy: + def export(self, call: CapturedLLMCall) -> None: + seen.append(call) + + capture.register_exporter(_Spy()) + assert capture.has_exporters() is True + + call = build_captured_call( + telemetry=None, + transport="anthropic", + provider_label=None, + model="m", + messages=[], + tools=None, + tool_choice=None, + result=None, + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + capture.dispatch_captured_call(call) + assert seen == [call] + capture.clear_exporters() + assert capture.has_exporters() is False + + def test_dispatch_swallows_exporter_errors(self): + capture.clear_exporters() + + class _Boom: + def export(self, call: CapturedLLMCall) -> None: + raise RuntimeError(f"nope: {call.model}") + + capture.register_exporter(_Boom()) + call = build_captured_call( + telemetry=None, + transport="anthropic", + provider_label=None, + model="m", + messages=[], + tools=None, + tool_choice=None, + result=None, + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + # Must not raise — telemetry never breaks the LLM path. + capture.dispatch_captured_call(call) + capture.clear_exporters() + + +class TestThoughtSignatureSerialization: + """Gemini `thought_signature` is bytes; it must not break trace serialization.""" + + def test_bytes_signature_base64_encoded_and_serializes(self): + import json + + from src.telemetry.events.trace import LLMCallTracedEvent + + result = CompletionResult( + content=None, + finish_reason="STOP", + tool_calls=[ + ToolCallResult( + id="call_1", + name="grep_messages", + input={"text": "coffee"}, + thought_signature=b"\x0a\x1f\x88\xff\x00sig", + ) + ], + ) + call = build_captured_call( + telemetry=LLMTelemetryContext(trace_id="t1", span_id="s1"), + transport="gemini", + provider_label=None, + model="gemini-2.5-flash", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=result, + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="STOP", + ) + sig = call.output_tool_calls[0]["thought_signature"] + assert isinstance(sig, str) # base64, not raw bytes + + # The traced event must serialize to JSON without raising (the emit path + # calls model_dump(mode="json"), which threw UnicodeDecodeError on bytes). + event = LLMCallTracedEvent( + model="gemini-2.5-flash", + transport="gemini", + output_tool_calls=call.output_tool_calls, + ) + json.dumps(event.model_dump(mode="json")) diff --git a/tests/llm/test_langfuse_trace_annotation.py b/tests/llm/test_langfuse_trace_annotation.py index e94e5acb..2f1ec50a 100644 --- a/tests/llm/test_langfuse_trace_annotation.py +++ b/tests/llm/test_langfuse_trace_annotation.py @@ -95,25 +95,16 @@ def langfuse_client(monkeypatch: pytest.MonkeyPatch): @pytest.fixture def langfuse_enabled(monkeypatch: pytest.MonkeyPatch): - """Turn the integration on with a known NAMESPACE (the tenant / user_id).""" + """Turn the integration on with a known NAMESPACE (the tenant / user_id). + + Pins LANGFUSE_EXPORTER_MODE='inline' — this module tests the legacy inline + span machinery, which is gated to inline mode (the default is now 'exporter', + where these functions no-op in favor of the LangfuseExporter).""" monkeypatch.setattr(settings, "LANGFUSE_PUBLIC_KEY", "pk-test") + monkeypatch.setattr(settings, "LANGFUSE_EXPORTER_MODE", "inline") monkeypatch.setattr(settings, "NAMESPACE", "acme-tenant") -@contextlib.contextmanager -def _inside_agent_run(): - """Set the `_in_agent_run` ContextVar for the body, resetting it after. - - Simulates execution nested inside a run handle without opening one (which - would itself call propagate_attributes and pollute the capture). - """ - token = runtime._in_agent_run.set(True) - try: - yield - finally: - runtime._in_agent_run.reset(token) - - class TestAnnotateDisabled: def test_noop_when_key_unset( self, monkeypatch: pytest.MonkeyPatch, capture_propagate: dict[str, Any] @@ -130,10 +121,11 @@ class TestAnnotateDisabled: class TestAnnotateInsideRun: - """A generation nested inside an active run handle: the run owns the trace - attrs, so this call must NOT propagate. It still stamps model + per-step - metadata + name on the generation (the multi-turn regression fix — - provider/model used to be dropped on every iteration after the first).""" + """A generation nested under a run (it carries a `parent_span_id`): the run + owns the trace attrs, so this call must NOT propagate. It still stamps model + + per-step metadata + name on the generation (the multi-turn regression fix — + provider/model used to be dropped on every iteration after the first). + Nesting is derived from the explicit `parent_span_id`, not a contextvar.""" def test_nested_generation_does_not_propagate( self, @@ -146,15 +138,18 @@ class TestAnnotateInsideRun: call_purpose="dialectic.answer", agent_type="dialectic", run_id="run-abc", + span_id="run-abc", + # A non-null parent_span_id is what marks this generation as nested + # under the run span (replaces the old `_in_agent_run` contextvar). + parent_span_id="run-abc", iteration=2, peer_name="alice", track_name="Dialectic Agent", ) - with _inside_agent_run(): - runtime.annotate_current_langfuse_trace( - "anthropic", "claude-x", telemetry=telemetry - ) + runtime.annotate_current_langfuse_trace( + "anthropic", "claude-x", telemetry=telemetry + ) # Run handle owns user_id/session_id/trace_name — re-propagating here # would clobber the run's session, so we don't propagate at all. @@ -300,23 +295,45 @@ class TestAgentRun: finally: handle.end() - def test_marks_in_agent_run_for_nested_calls( + def test_run_keyed_on_span_id_and_nesting_via_parent_span_id( self, langfuse_enabled: None, langfuse_client: dict[str, dict[str, Any]], capture_propagate: dict[str, Any], ): - # While the run handle is live, nested generations see _in_agent_run - # set so they stay silent (the run owns the trace attrs); end() resets it. - assert runtime._in_agent_run.get() is False + # The `_in_agent_run` contextvar is retired — nesting is now derived + # from the explicit `parent_span_id` field on the telemetry context. + assert not hasattr(runtime, "_in_agent_run") + + # The run handle opens keyed on span_id (falling back to run_id). handle = runtime.start_langfuse_agent_run( "Dialectic Agent", - LLMTelemetryContext(run_id="r1", track_name="Dialectic Agent"), + LLMTelemetryContext( + run_id="r1", span_id="r1", track_name="Dialectic Agent" + ), ) assert handle is not None - assert runtime._in_agent_run.get() is True handle.end() - assert runtime._in_agent_run.get() is False + + # A root call (no parent_span_id) propagates trace attrs; a nested call + # (parent_span_id set) stays silent. + capture_propagate.clear() + runtime.annotate_current_langfuse_trace( + "anthropic", + "claude-x", + telemetry=LLMTelemetryContext(run_id="r2", span_id="r2"), + ) + assert capture_propagate.get("session_id") == "r2" + + capture_propagate.clear() + runtime.annotate_current_langfuse_trace( + "anthropic", + "claude-x", + telemetry=LLMTelemetryContext( + run_id="r2", span_id="r2", parent_span_id="r2" + ), + ) + assert capture_propagate == {} def test_end_is_idempotent( self, @@ -497,3 +514,49 @@ class TestStepIO: assert langfuse_client["run_span"]["output"] == { "tool_calls": ["grep_messages", "search_memory"] } + + +class TestAnnotateGenerationIOGating: + """`annotate_current_generation_io` writes to the ACTIVE @observe generation + span (the `conditional_observe` wrapper), which only exists in inline mode. + In exporter mode — the default — there is no active span, so calling + `update_current_generation()` would make the Langfuse SDK log "No active span + in current context" on every LLM call. The helper must therefore no-op in + exporter mode (the LangfuseExporter projects I/O from the captured stream). + Regression guard for the gate that was on LANGFUSE_PUBLIC_KEY instead of + langfuse_inline_enabled.""" + + def test_noops_in_exporter_mode_even_with_key( + self, + monkeypatch: pytest.MonkeyPatch, + langfuse_client: dict[str, dict[str, Any]], + ): + # Key present but exporter mode (the production default). + monkeypatch.setattr(settings, "LANGFUSE_PUBLIC_KEY", "pk-test") + monkeypatch.setattr(settings, "LANGFUSE_EXPORTER_MODE", "exporter") + + runtime.annotate_current_generation_io( + input=[{"role": "user", "content": "hi"}], + output="hello", + usage_details={"input": 1, "output": 1}, + ) + + # No active generation span in exporter mode → must not touch it. + assert langfuse_client["generation"] == {} + + def test_writes_in_inline_mode( + self, + langfuse_enabled: None, # pins inline mode + a key + langfuse_client: dict[str, dict[str, Any]], + ): + messages = [{"role": "user", "content": "hi"}] + runtime.annotate_current_generation_io( + input=messages, + output="hello", + usage_details={"input": 1, "output": 1}, + ) + + gen = langfuse_client["generation"] + assert gen["input"] == messages + assert gen["output"] == "hello" + assert gen["usage_details"] == {"input": 1, "output": 1} diff --git a/tests/llm/test_telemetry_agent_iteration.py b/tests/llm/test_telemetry_agent_iteration.py index 382cc2e3..71f5c4ba 100644 --- a/tests/llm/test_telemetry_agent_iteration.py +++ b/tests/llm/test_telemetry_agent_iteration.py @@ -45,7 +45,7 @@ def _response( class TestTelemetryForIteration: def test_returns_none_when_base_is_none(self): - assert _telemetry_for_iteration(None, 1) is None + assert _telemetry_for_iteration(None, 1, step_seq=1) is None def test_returns_fresh_copy_with_iteration_set(self): base = LLMTelemetryContext( @@ -54,12 +54,13 @@ class TestTelemetryForIteration: parent_category="dialectic", agent_type="dialectic", run_id="run-xyz", + span_id="run-xyz", iteration=None, peer_name="user_peer", ) - copy_a = _telemetry_for_iteration(base, 3) - copy_b = _telemetry_for_iteration(base, 4) + copy_a = _telemetry_for_iteration(base, 3, step_seq=3) + copy_b = _telemetry_for_iteration(base, 4, step_seq=4) assert copy_a is not None and copy_b is not None assert copy_a is not base and copy_b is not base @@ -67,6 +68,9 @@ class TestTelemetryForIteration: assert base.iteration is None assert copy_a.iteration == 3 assert copy_b.iteration == 4 + # Per-step correlation is set; parent_span_id is derived from the span. + assert copy_a.step_seq == 3 + assert copy_a.parent_span_id == "run-xyz" # All other fields round-trip. assert copy_a.run_id == "run-xyz" assert copy_a.peer_name == "user_peer" diff --git a/tests/telemetry/conftest.py b/tests/telemetry/conftest.py index f871e22d..442f6264 100644 --- a/tests/telemetry/conftest.py +++ b/tests/telemetry/conftest.py @@ -35,6 +35,42 @@ from src.telemetry.events.reconciliation import ( ) from src.telemetry.events.representation import RepresentationCompletedEvent +# ============================================================================= +# Global trace-state isolation +# ============================================================================= + + +@pytest.fixture(autouse=True) +def _isolate_trace_globals(): # pyright: ignore[reportUnusedFunction] + """Snapshot/restore process-global trace state around every telemetry test. + + `initialize_telemetry_events()` (exercised in test_emit_function) registers a + real ``TraceExporter`` into ``capture._EXPORTERS`` and starts a real trace + emitter (``emitter._trace_emitter``). Without cleanup that state bleeds into + the trace-exporter tests, which then fail — and because xdist schedules tests + across workers nondeterministically, the failure looks flaky (a different + trace test fails each run depending on who shared its worker). + + Snapshotting these globals (and resetting the per-run dedup) before/after + each test makes the trace tests hermetic regardless of neighbor ordering. + """ + from src.llm import capture + from src.telemetry import emitter as emitter_mod + from src.telemetry import langfuse_session, trace_session + + saved_exporters = list(capture._EXPORTERS) # pyright: ignore[reportPrivateUsage] + saved_trace_emitter = emitter_mod._trace_emitter # pyright: ignore[reportPrivateUsage] + trace_session.reset() + langfuse_session.reset() + try: + yield + finally: + capture._EXPORTERS[:] = saved_exporters # pyright: ignore[reportPrivateUsage] + emitter_mod._trace_emitter = saved_trace_emitter # pyright: ignore[reportPrivateUsage] + trace_session.reset() + langfuse_session.reset() + + # ============================================================================= # Fixed timestamp for deterministic tests # ============================================================================= diff --git a/tests/telemetry/test_cross_agent_trace.py b/tests/telemetry/test_cross_agent_trace.py new file mode 100644 index 00000000..b6364ed4 --- /dev/null +++ b/tests/telemetry/test_cross_agent_trace.py @@ -0,0 +1,215 @@ +# pyright: reportPrivateUsage=false, reportUnannotatedClassAttribute=false, reportUnusedFunction=false, reportUnknownLambdaType=false, reportUnknownArgumentType=false, reportArgumentType=false +"""Cross-agent trace-metadata contract. + +Verifies that each agent's telemetry produces a well-formed `CapturedLLMCall` +with the right correlation/session/identity fields, and that the SAME captured +call fans out to BOTH exporters (CloudEvents + Langfuse) — the "one data model, +two projections" invariant. + +This is the metadata-correctness bar across agents. It drives the real +`DialecticAgent` telemetry and the real `dispatch_captured_call`; the other +agents are represented by the telemetry contexts they construct (cited inline). +Full end-to-end capture through a live stack (real subprocesses feeding a trace +sink) is exercised separately, outside this unit suite. +""" + +from __future__ import annotations + +import pytest + +from src.config import settings +from src.dialectic.core import DialecticAgent +from src.llm import capture as capture_mod +from src.llm.backend import CompletionResult +from src.llm.capture import ( + CapturedLLMCall, + build_captured_call, + dispatch_captured_call, + register_exporter, +) +from src.llm.types import LLMTelemetryContext +from src.telemetry.langfuse_exporter import LangfuseExporter + + +class SpyExporter: + def __init__(self) -> None: + self.calls: list[CapturedLLMCall] = [] + + def export(self, call: CapturedLLMCall) -> None: + self.calls.append(call) + + +@pytest.fixture +def spy() -> SpyExporter: + """Clean exporter registry with a single spy (restored by the telemetry + conftest's _isolate_trace_globals).""" + capture_mod._EXPORTERS.clear() + exporter = SpyExporter() + register_exporter(exporter) + return exporter + + +def _dispatch(telemetry: LLMTelemetryContext, *, content: str = "answer") -> None: + call = build_captured_call( + telemetry=telemetry, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=CompletionResult(content=content, finish_reason="stop"), + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + dispatch_captured_call(call) + + +# --- Dialectic: real agent telemetry -------------------------------------- + + +def test_dialectic_with_session_sets_session_id(spy: SpyExporter): + agent = DialecticAgent( + workspace_name="ws", + session_name="my-session", + session_id="sess-nanoid", + observer="alice", + observed="bob", + ) + _dispatch(agent._telemetry_context("Dialectic Agent")) + + call = spy.calls[-1] + assert call.session_id == "sess-nanoid" + assert call.agent_type == "dialectic" + # Root of the invocation: trace_id == span_id == run_id, parent normalized off. + assert call.trace_id == call.span_id == agent._run_id + assert call.parent_span_id is None + assert call.track_name == "Dialectic Agent" + + +def test_dialectic_global_has_no_session(spy: SpyExporter): + agent = DialecticAgent( + workspace_name="ws", + session_name=None, + session_id=None, + observer="alice", + observed="alice", + ) + _dispatch(agent._telemetry_context("Dialectic Agent")) + assert spy.calls[-1].session_id is None + + +# --- Background agents: sessionless single-shot / shared-tree contracts ----- + + +@pytest.mark.parametrize( + ("call_purpose", "parent_category", "track_name"), + [ + ("deriver.representation", "representation", "Minimal Deriver"), + ("summary.short", "summary", None), + ], +) +def test_background_agents_are_sessionless_single_shot( + spy: SpyExporter, + call_purpose: str, + parent_category: str, + track_name: str | None, +): + # Deriver + summarizer mirror their src/ contexts: trace_id == span_id, no + # run_id/session_id, self-rooted. + tid = f"{parent_category}-trace" + _dispatch( + LLMTelemetryContext( + workspace_name="ws", + call_purpose=call_purpose, + parent_category=parent_category, + track_name=track_name, + trace_id=tid, + span_id=tid, + ) + ) + call = spy.calls[-1] + assert call.session_id is None + assert call.run_id is None + assert call.trace_id == call.span_id == tid + assert call.parent_span_id is None + + +def test_dreamer_specialists_share_one_tree(spy: SpyExporter): + # Single-dream-tree (this PR): both specialists reuse the orchestrator run_id + # as trace_id (src/dreamer/specialists.py), session_id None. + run_id = "dream-run" + for agent_type in ("deduction", "induction"): + _dispatch( + LLMTelemetryContext( + workspace_name="ws", + call_purpose=f"dream.{agent_type}", + parent_category="dream", + agent_type=agent_type, + run_id=run_id, + trace_id=run_id, + span_id=run_id, + observer="assistant", + observed="bob", + iteration=1, + ) + ) + ded, ind = spy.calls[-2], spy.calls[-1] + assert ded.trace_id == ind.trace_id == run_id # one shared tree + assert ded.session_id is None and ind.session_id is None + assert ded.agent_type == "deduction" and ind.agent_type == "induction" + + +# --- One data model, two projections --------------------------------------- + + +def test_same_call_reaches_both_exporters( + spy: SpyExporter, monkeypatch: pytest.MonkeyPatch +): + """A dispatched call fans out to the CloudEvents spy AND the LangfuseExporter.""" + monkeypatch.setattr(settings, "LANGFUSE_PUBLIC_KEY", "pk-test") + monkeypatch.setattr(settings, "LANGFUSE_EXPORTER_MODE", "exporter") + monkeypatch.setattr(settings, "NAMESPACE", "tenant1") + + created: list[dict[str, object]] = [] + + class FakeOtel: + def set_attribute(self, *_a: object) -> None: ... + + class FakeObs: + def __init__(self, **kwargs: object) -> None: + self.id = "obs" + self.kwargs = kwargs + self._otel_span = FakeOtel() + + def end(self) -> None: ... + + class FakeClient: + def create_trace_id(self, *, seed: str | None = None) -> str: + return f"lf-{seed}" + + def start_observation(self, **kwargs: object) -> FakeObs: + created.append(kwargs) + return FakeObs(**kwargs) + + import langfuse + + monkeypatch.setattr(langfuse, "get_client", lambda: FakeClient()) + register_exporter(LangfuseExporter()) + + agent = DialecticAgent( + workspace_name="ws", + session_name="s", + session_id="sess-1", + observer="alice", + observed="bob", + ) + _dispatch(agent._telemetry_context("Dialectic Agent")) + + # CloudEvents projection saw the raw captured call... + assert spy.calls and spy.calls[-1].session_id == "sess-1" + # ...and the Langfuse projection built observations from the SAME call. + assert created, "LangfuseExporter produced no observations" + assert any(o.get("as_type") == "generation" for o in created) diff --git a/tests/telemetry/test_embedding_trace.py b/tests/telemetry/test_embedding_trace.py new file mode 100644 index 00000000..a878e4f3 --- /dev/null +++ b/tests/telemetry/test_embedding_trace.py @@ -0,0 +1,111 @@ +# pyright: reportPrivateUsage=false, reportUnannotatedClassAttribute=false, reportUnusedFunction=false, reportUnknownLambdaType=false, reportUnknownArgumentType=false, reportArgumentType=false +"""Tests for embedding calls joining the trace stream. + +`_publish_embedding_event` emits an `EmbeddingCallTracedEvent` (gated on +TRACE_PAYLOADS_ENABLED) in addition to the metrics-grade completed event, carrying the +span-tree correlation from the embedding ContextVars so an embedding made inside +an agent run nests under that run's trace. +""" + +from __future__ import annotations + +import pytest + +import src.telemetry.events as events_mod +from src.config import settings +from src.embedding_client import _publish_embedding_event +from src.telemetry.events.trace import EmbeddingCallTracedEvent +from src.utils.types import embedding_call_purpose + + +@pytest.fixture +def capture_emits(monkeypatch: pytest.MonkeyPatch): + """Capture emit()/emit_trace() without a live emitter.""" + traced: list[object] = [] + monkeypatch.setattr(events_mod, "emit", lambda _e: None) + monkeypatch.setattr(events_mod, "emit_trace", lambda e: traced.append(e)) + return traced + + +def test_embedding_traced_event_carries_correlation( + capture_emits: list[object], monkeypatch: pytest.MonkeyPatch +): + monkeypatch.setattr(settings.TELEMETRY, "TRACE_PAYLOADS_ENABLED", True) + with embedding_call_purpose( + "dialectic.prefetch", + workspace_name="ws", + run_id="run-1", + parent_category="dialectic", + session_id="sess-1", + ): + _publish_embedding_event( + provider="openai", + model="text-embedding-3", + input_count=1, + input_tokens_estimate=7, + duration_ms=1.0, + outcome="success", + error=None, + is_final_attempt=True, + ) + + assert len(capture_emits) == 1 + ev = capture_emits[0] + assert isinstance(ev, EmbeddingCallTracedEvent) + # The embedding gets its own span under the run: trace_id/parent are the + # run_id, span_id is a fresh id so sibling embeddings don't collide. + assert ev.trace_id == "run-1" + assert ev.parent_span_id == "run-1" + assert ev.span_id and ev.span_id != "run-1" + assert ev.session_id == "sess-1" + assert ev.call_purpose == "dialectic.prefetch" + assert ev.parent_category == "dialectic" + assert ev.provider == "openai" and ev.model == "text-embedding-3" + assert ev.provider_input_tokens == 7 + assert ev.provider_output_tokens == 0 + assert ev.input_count == 1 + + +def test_no_trace_event_when_payloads_off( + capture_emits: list[object], monkeypatch: pytest.MonkeyPatch +): + monkeypatch.setattr(settings.TELEMETRY, "TRACE_PAYLOADS_ENABLED", False) + with embedding_call_purpose("dialectic.prefetch", run_id="run-1"): + _publish_embedding_event( + provider="openai", + model="m", + input_count=2, + input_tokens_estimate=3, + duration_ms=1.0, + outcome="success", + error=None, + is_final_attempt=True, + ) + assert capture_emits == [] + + +def test_sessionless_embedding_has_no_session( + capture_emits: list[object], monkeypatch: pytest.MonkeyPatch +): + # A deriver/reconciler embedding (no session scope) traces with session None. + monkeypatch.setattr(settings.TELEMETRY, "TRACE_PAYLOADS_ENABLED", True) + with embedding_call_purpose( + "deriver", workspace_name="ws", parent_category="deriver" + ): + _publish_embedding_event( + provider="gemini", + model="emb", + input_count=5, + input_tokens_estimate=20, + duration_ms=2.0, + outcome="success", + error=None, + is_final_attempt=True, + ) + assert len(capture_emits) == 1 + ev = capture_emits[0] + assert isinstance(ev, EmbeddingCallTracedEvent) + assert ev.session_id is None + # No run_id → the span self-roots (trace_id == span_id) with no parent. + assert ev.parent_span_id is None + assert ev.span_id and ev.trace_id == ev.span_id diff --git a/tests/telemetry/test_emit_function.py b/tests/telemetry/test_emit_function.py index c4e2c8ad..1e8f78f9 100644 --- a/tests/telemetry/test_emit_function.py +++ b/tests/telemetry/test_emit_function.py @@ -314,6 +314,11 @@ class TestInitializeTelemetryEvents: mock_settings.TELEMETRY.FLUSH_THRESHOLD = 50 mock_settings.TELEMETRY.MAX_RETRIES = 3 mock_settings.TELEMETRY.MAX_BUFFER_SIZE = 10000 + # This test only covers the primary emitter. Pin trace payloads off + # so we don't fall into the trace branch and start a *real* trace + # emitter + register a real TraceExporter (a MagicMock here is + # truthy) — that global state would leak into other tests. + mock_settings.TELEMETRY.TRACE_PAYLOADS_ENABLED = False mock_init.return_value = AsyncMock() await initialize_telemetry_events() @@ -378,8 +383,10 @@ class TestInitializeTelemetryAsync: mock_ce_init.assert_called_once() @pytest.mark.asyncio - async def test_skip_cloudevents_when_disabled(self): - """initialize_telemetry_async() skips CloudEvents when disabled.""" + async def test_skip_when_telemetry_disabled(self): + """TELEMETRY.ENABLED is the master switch — no init when it's off, even + with the Langfuse exporter configured (no traces for open-source users + who leave telemetry off).""" from src.telemetry import initialize_telemetry_async with ( @@ -390,6 +397,7 @@ class TestInitializeTelemetryAsync: ) as mock_ce_init, ): mock_settings.TELEMETRY.ENABLED = False + mock_settings.langfuse_exporter_enabled = True await initialize_telemetry_async() diff --git a/tests/telemetry/test_events.py b/tests/telemetry/test_events.py index ef6f4ffb..bce0a38c 100644 --- a/tests/telemetry/test_events.py +++ b/tests/telemetry/test_events.py @@ -759,10 +759,11 @@ class TestAgentToolSummaryCreatedEvent: def test_get_resource_id( self, sample_summary_created_event: AgentToolSummaryCreatedEvent ): - """get_resource_id() returns run_id:iteration:summary_created format.""" + """get_resource_id() keys on message_id:summary_type (run_id/iteration are + None for the non-agentic summarizer and can't identify the summary).""" assert ( sample_summary_created_event.get_resource_id() - == "ghi11111:1:summary_created" + == "msg_020:short:summary_created" ) def test_summary_type_values(self, fixed_timestamp: datetime): diff --git a/tests/telemetry/test_langfuse_exporter.py b/tests/telemetry/test_langfuse_exporter.py new file mode 100644 index 00000000..36f3c9c2 --- /dev/null +++ b/tests/telemetry/test_langfuse_exporter.py @@ -0,0 +1,438 @@ +# pyright: reportPrivateUsage=false, reportUnannotatedClassAttribute=false, reportUnusedFunction=false, reportUnknownLambdaType=false, reportUnknownArgumentType=false, reportArgumentType=false, reportIndexIssue=false +"""Tests for the Langfuse projection over the captured LLM stream. + +Exercises `LangfuseExporter` with a fake Langfuse client so we can assert the +reconstructed trace tree (trace ids, parent linkage, names, usage, trace-level +user attributes, session-as-metadata) without a real Langfuse backend. +""" + +from __future__ import annotations + +import pytest + +from src.config import settings +from src.llm.backend import CompletionResult, ToolCallResult +from src.llm.capture import build_captured_call +from src.llm.types import LLMTelemetryContext +from src.telemetry import langfuse_session +from src.telemetry.langfuse_exporter import LangfuseExporter + + +class FakeOtelSpan: + def __init__(self) -> None: + self.attributes: dict[str, object] = {} + + def set_attribute(self, key: str, value: object) -> None: + self.attributes[key] = value + + +class FakeObs: + _counter = 0 + + def __init__(self, **kwargs: object) -> None: + FakeObs._counter += 1 + self.id = f"obs-{FakeObs._counter}" + self.kwargs = kwargs + self._otel_span = FakeOtelSpan() + self.ended = False + + def end(self) -> None: + self.ended = True + + +class FakeClient: + def __init__(self) -> None: + self.observations: list[FakeObs] = [] + + def create_trace_id(self, *, seed: str | None = None) -> str: + return f"lf-{seed}" + + def start_observation(self, **kwargs: object) -> FakeObs: + obs = FakeObs(**kwargs) + self.observations.append(obs) + return obs + + +@pytest.fixture(autouse=True) +def _exporter_env(monkeypatch: pytest.MonkeyPatch): + """Enable the exporter and install a fake langfuse client + clean registry.""" + monkeypatch.setattr(settings, "LANGFUSE_PUBLIC_KEY", "pk-test") + monkeypatch.setattr(settings, "LANGFUSE_EXPORTER_MODE", "exporter") + monkeypatch.setattr(settings, "NAMESPACE", "tenant1") + client = FakeClient() + import langfuse + + monkeypatch.setattr(langfuse, "get_client", lambda: client) + langfuse_session.reset() + FakeObs._counter = 0 + yield client + langfuse_session.reset() + + +def _call( + *, + run_id: str | None, + trace_id: str, + iteration: int | None = None, + step_seq: int = 0, + attempt: int = 1, + session_id: str | None = None, + track_name: str | None = None, + agent_type: str = "dialectic", + parent_category: str = "dialectic", + tool_names: list[str] | None = None, + finish_reason: str = "stop", + content: str = "answer", +): + telemetry = LLMTelemetryContext( + workspace_name="ws", + call_purpose="dialectic.answer", + parent_category=parent_category, + agent_type=agent_type, + run_id=run_id, + trace_id=trace_id, + span_id=trace_id, + session_id=session_id, + track_name=track_name, + iteration=iteration, + step_seq=step_seq, + ) + result = CompletionResult( + content=content, + input_tokens=10, + output_tokens=5, + cache_read_input_tokens=2, + finish_reason=finish_reason, + tool_calls=[ + ToolCallResult(id=f"tc-{i}", name=name, input={"q": name}) + for i, name in enumerate(tool_names or []) + ], + ) + return build_captured_call( + telemetry=telemetry, + transport="anthropic", + provider_label=None, + model="claude-x", + messages=[{"role": "user", "content": "q"}], + tools=None, + tool_choice=None, + result=result, + attempt=attempt, + was_fallback=False, + was_stream=False, + finish_reason=finish_reason, + ) + + +def test_single_shot_generation_is_trace_root(_exporter_env: FakeClient): + # Deriver/summarizer style: run_id None → no run/step span, generation is root. + client = _exporter_env + LangfuseExporter().export( + _call(run_id=None, trace_id="t1", track_name="Minimal Deriver") + ) + + assert len(client.observations) == 1 + gen = client.observations[0] + assert gen.kwargs["as_type"] == "generation" + assert gen.kwargs["trace_context"] == {"trace_id": "lf-t1"} + assert gen.kwargs["model"] == "claude-x" + assert gen.kwargs["usage_details"] == { + "input": 10, + "output": 5, + "cache_read_input_tokens": 2, + "cache_creation_input_tokens": 0, + } + # Trace attrs stamped on the root generation; no session (session_id None). + assert gen._otel_span.attributes.get("user.id") == "tenant1" + assert "session.id" not in gen._otel_span.attributes + + +def test_agentic_run_builds_run_step_generation(_exporter_env: FakeClient): + client = _exporter_env + LangfuseExporter().export( + _call( + run_id="r1", + trace_id="r1", + iteration=1, + session_id="sess_abc", + track_name="Dialectic Agent", + ) + ) + + by_type: dict[str, list[FakeObs]] = {} + for obs in client.observations: + by_type.setdefault(str(obs.kwargs["as_type"]), []).append(obs) + assert len(by_type["span"]) == 2 # run span + step span + assert len(by_type["generation"]) == 1 + + run_span, step_span = by_type["span"] + gen = by_type["generation"][0] + assert run_span.kwargs["trace_context"] == {"trace_id": "lf-r1"} + assert step_span.kwargs["trace_context"] == { + "trace_id": "lf-r1", + "parent_span_id": run_span.id, + } + assert gen.kwargs["trace_context"] == { + "trace_id": "lf-r1", + "parent_span_id": step_span.id, + } + # Trace attrs stamped once, on the run span (the root). The Honcho session is + # NOT a Langfuse session (one-shot queries aren't a conversation thread) — it + # rides in metadata as a correlation key instead. + assert "session.id" not in run_span._otel_span.attributes + assert run_span._otel_span.attributes["user.id"] == "tenant1" + assert run_span._otel_span.attributes["langfuse.trace.name"] == "Dialectic Agent" + assert run_span.kwargs["metadata"]["honcho_session"] == "sess_abc" + + +def test_run_span_created_once_across_iterations(_exporter_env: FakeClient): + client = _exporter_env + exporter = LangfuseExporter() + exporter.export(_call(run_id="r1", trace_id="r1", iteration=1, session_id="s")) + exporter.export(_call(run_id="r1", trace_id="r1", iteration=2, session_id="s")) + + spans = [o for o in client.observations if o.kwargs["as_type"] == "span"] + gens = [o for o in client.observations if o.kwargs["as_type"] == "generation"] + # One run span shared, one step span per iteration, one generation per call. + assert len(gens) == 2 + assert len(spans) == 3 # 1 run + 2 step + # Trace attrs (user/name) stamped exactly once across the whole run. + stamped = [o for o in client.observations if "user.id" in o._otel_span.attributes] + assert len(stamped) == 1 + + +def test_langfuse_session_lru_evicts_least_recently_used( + monkeypatch: pytest.MonkeyPatch, +): + """Past _MAX_TRACES the least-recently-touched trace is evicted (not refused), + so an active trace keeps its remembered span ids no matter the run volume.""" + langfuse_session.reset() + monkeypatch.setattr(langfuse_session, "_MAX_TRACES", 2) + + langfuse_session.ensure_run_span("t1", "b", lambda _s: "t1-span") + langfuse_session.ensure_run_span("t2", "b", lambda _s: "t2-span") + # Touch t1 so t2 becomes the least-recently-used trace. + assert ( + langfuse_session.ensure_run_span("t1", "b", lambda _s: "ignored") == "t1-span" + ) + # A third trace evicts the LRU trace (t2), keeping t1. + langfuse_session.ensure_run_span("t3", "b", lambda _s: "t3-span") + + created: list[str] = [] + # t1 still tracked → remembered span returned, create NOT re-invoked. + assert ( + langfuse_session.ensure_run_span( + "t1", "b", lambda _s: created.append("t1") or "new" + ) + == "t1-span" + ) + assert created == [] + # t2 was evicted → fresh state, create IS re-invoked. + assert ( + langfuse_session.ensure_run_span( + "t2", "b", lambda _s: created.append("t2") or "t2-span2" + ) + == "t2-span2" + ) + assert created == ["t2"] + + +def test_error_finish_marks_generation_level(_exporter_env: FakeClient): + client = _exporter_env + LangfuseExporter().export( + _call(run_id=None, trace_id="t1", finish_reason="error", content="") + ) + gen = client.observations[0] + assert gen.kwargs["level"] == "ERROR" + + +@pytest.mark.parametrize( + ("attr", "value"), + [ + ("LANGFUSE_EXPORTER_MODE", "inline"), # exporter off in inline mode + ("LANGFUSE_PUBLIC_KEY", None), # exporter off without a public key + ], +) +def test_exporter_disabled_emits_nothing( + _exporter_env: FakeClient, + monkeypatch: pytest.MonkeyPatch, + attr: str, + value: object, +): + client = _exporter_env + monkeypatch.setattr(settings, attr, value) + LangfuseExporter().export(_call(run_id="r1", trace_id="r1", iteration=1)) + assert client.observations == [] + + +def test_generation_name_uses_generation_suffix(_exporter_env: FakeClient): + client = _exporter_env + LangfuseExporter().export( + _call(run_id="r1", trace_id="r1", iteration=1, track_name="Dialectic Agent") + ) + gen = [o for o in client.observations if o.kwargs["as_type"] == "generation"][0] + assert gen.kwargs["name"] == "Dialectic Agent generation" + step = [o for o in client.observations if o.kwargs["as_type"] == "span"][1] + assert step.kwargs["name"] == "Dialectic Agent step" + + +def test_tool_calls_become_spans_under_the_step(_exporter_env: FakeClient): + client = _exporter_env + LangfuseExporter().export( + _call( + run_id="r1", + trace_id="r1", + iteration=1, + track_name="Dialectic Agent", + tool_names=["search_memory", "search_messages"], + ) + ) + + spans = [o for o in client.observations if o.kwargs["as_type"] == "span"] + gen = [o for o in client.observations if o.kwargs["as_type"] == "generation"][0] + tools = [o for o in client.observations if o.kwargs["as_type"] == "tool"] + step_span = spans[1] # run span, then step span + + assert [t.kwargs["name"] for t in tools] == ["search_memory", "search_messages"] + # Tool spans are siblings of the generation: same parent (the step span). + for t in tools: + assert t.kwargs["trace_context"]["parent_span_id"] == step_span.id + assert gen.kwargs["trace_context"]["parent_span_id"] == step_span.id + # The model's requested input args ride on the tool span. + assert tools[0].kwargs["input"] == {"q": "search_memory"} + + +def test_only_the_root_span_keeps_as_root(_exporter_env: FakeClient): + # The SDK stamps AS_ROOT on every trace_context span; the exporter must + # demote children so exactly one root survives — otherwise Langfuse races to + # pick the trace name/root and names the trace after a child span. + from langfuse import LangfuseOtelSpanAttributes as Attr + + client = _exporter_env + LangfuseExporter().export( + _call( + run_id="r1", + trace_id="r1", + iteration=1, + track_name="Dialectic Agent", + tool_names=["search_memory"], + ) + ) + + def is_demoted(obs: FakeObs) -> bool: + return obs._otel_span.attributes.get(Attr.AS_ROOT) is False + + spans = [o for o in client.observations if o.kwargs["as_type"] == "span"] + run_span, step_span = spans[0], spans[1] + gen = [o for o in client.observations if o.kwargs["as_type"] == "generation"][0] + tools = [o for o in client.observations if o.kwargs["as_type"] == "tool"] + + # Exactly one root: the run span is never demoted; everything with a real + # parent is. + assert not is_demoted(run_span) + assert is_demoted(step_span) + assert is_demoted(gen) + assert all(is_demoted(t) for t in tools) + demoted = [o for o in client.observations if is_demoted(o)] + assert len(demoted) == len(client.observations) - 1 + + +def test_single_shot_generation_keeps_as_root(_exporter_env: FakeClient): + # No parent → the generation is the trace root and must not be demoted. + from langfuse import LangfuseOtelSpanAttributes as Attr + + client = _exporter_env + LangfuseExporter().export( + _call(run_id=None, trace_id="t1", track_name="Minimal Deriver") + ) + gen = client.observations[0] + assert gen._otel_span.attributes.get(Attr.AS_ROOT) is not False + + +def test_single_shot_tool_calls_are_skipped(_exporter_env: FakeClient): + # No step span to anchor to (deriver-style); tools don't orphan to the root. + client = _exporter_env + LangfuseExporter().export( + _call(run_id=None, trace_id="t1", tool_names=["search_memory"]) + ) + assert [o.kwargs["as_type"] for o in client.observations] == ["generation"] + + +def test_dreamer_specialists_nest_under_one_dream_root(_exporter_env: FakeClient): + # Both specialists share ONE dream trace (run_id) and both start at + # iteration 1. They must nest under a single synthetic "Dream" root (so the + # trace has one root, not one per specialist) while staying distinct + # sub-trees (no step-span collision). + from langfuse import LangfuseOtelSpanAttributes as Attr + + client = _exporter_env + exporter = LangfuseExporter() + for agent_type in ("deduction", "induction"): + exporter.export( + _call( + run_id="dream1", + trace_id="dream1", + iteration=1, + agent_type=agent_type, + parent_category="dream", + track_name=f"Dreamer/{agent_type}", + ) + ) + + by_name: dict[str, list[FakeObs]] = {} + for o in client.observations: + by_name.setdefault(str(o.kwargs["name"]), []).append(o) + gens = [o for o in client.observations if o.kwargs["as_type"] == "generation"] + + def is_demoted(o: FakeObs) -> bool: + return o._otel_span.attributes.get(Attr.AS_ROOT) is False + + # Exactly one trace root: the synthetic "Dream" span — no parent, not demoted. + roots = [ + o + for o in client.observations + if o.kwargs["trace_context"] == {"trace_id": "lf-dream1"} + ] + assert len(roots) == 1 + dream_root = roots[0] + assert dream_root.kwargs["name"] == "Dream" + assert dream_root.kwargs["as_type"] == "span" + assert not is_demoted(dream_root) + + # Both specialist run spans hang off the Dream root and are demoted. + run_dd = by_name["Dreamer/deduction"][0] + run_in = by_name["Dreamer/induction"][0] + assert len(by_name["Dreamer/deduction"]) == 1 + assert len(by_name["Dreamer/induction"]) == 1 + for rs in (run_dd, run_in): + assert rs.kwargs["trace_context"] == { + "trace_id": "lf-dream1", + "parent_span_id": dream_root.id, + } + assert is_demoted(rs) + + # One step span per specialist, parented to its own run span; no collapsing. + assert len(by_name["Dreamer/deduction step"]) == 1 + assert len(by_name["Dreamer/induction step"]) == 1 + assert ( + by_name["Dreamer/deduction step"][0].kwargs["trace_context"]["parent_span_id"] + == run_dd.id + ) + assert ( + by_name["Dreamer/induction step"][0].kwargs["trace_context"]["parent_span_id"] + == run_in.id + ) + + # Each generation nests under its OWN specialist's step. + assert len({g.kwargs["trace_context"]["parent_span_id"] for g in gens}) == 2 + + # Trace name is the branch-agnostic "Dream", stamped exactly once — on the + # Dream root, not on a specialist's run span. + named = [ + o + for o in client.observations + if o._otel_span.attributes.get("langfuse.trace.name") + ] + assert len(named) == 1 + assert named[0] is dream_root + assert named[0]._otel_span.attributes["langfuse.trace.name"] == "Dream" diff --git a/tests/telemetry/test_trace_events.py b/tests/telemetry/test_trace_events.py new file mode 100644 index 00000000..35da6492 --- /dev/null +++ b/tests/telemetry/test_trace_events.py @@ -0,0 +1,218 @@ +"""Tests for full-fidelity trace events, dedup, and the CloudEvents exporter.""" + +from __future__ import annotations + +from collections.abc import Iterator +from typing import Any + +import pytest + +from src.llm.backend import CompletionResult +from src.llm.capture import CapturedLLMCall, build_captured_call +from src.telemetry import trace_session +from src.telemetry.events.trace import LLMCallTracedEvent, TraceContentEvent + + +class TestLLMCallTracedEvent: + def test_metadata(self): + assert LLMCallTracedEvent.event_type() == "llm.call.traced" + assert LLMCallTracedEvent.category() == "trace" + # Ground-truth — never sampled (the system of record). + assert LLMCallTracedEvent.volume_class() == "ground_truth" + + def test_resource_id_format(self): + event = LLMCallTracedEvent( + span_id="s1", + iteration=2, + attempt=1, + step_seq=3, + transport="anthropic", + model="m", + ) + # {span_id}:{iteration}:{attempt}:{step_seq} — tool_call_seq dropped. + assert event.get_resource_id() == "s1:2:1:3" + + def test_keeps_default_evt_id(self): + event = LLMCallTracedEvent( + span_id="s1", + iteration=1, + attempt=1, + step_seq=1, + transport="anthropic", + model="m", + ) + event_id = event.generate_id() + assert event_id.startswith("evt_") + assert len(event_id) == 26 + + +class TestTraceContentEvent: + def test_metadata(self): + assert TraceContentEvent.event_type() == "trace.content" + assert TraceContentEvent.category() == "trace" + assert TraceContentEvent.volume_class() == "ground_truth" + + def test_resource_id_is_content_hash(self): + event = TraceContentEvent(content_hash="sha256:abc", role="user", content="hi") + assert event.get_resource_id() == "sha256:abc" + + def test_generate_id_is_content_addressed_and_timestamp_free(self): + # Two instances with the same hash but DIFFERENT timestamps must collide + # on id, so cross-process/retry re-sends dedupe at the transport layer. + import datetime + + a = TraceContentEvent( + content_hash="sha256:deadbeefdeadbeefdeadbeef", + role="user", + content="hi", + timestamp=datetime.datetime(2026, 1, 1, tzinfo=datetime.UTC), + ) + b = TraceContentEvent( + content_hash="sha256:deadbeefdeadbeefdeadbeef", + role="user", + content="hi", + timestamp=datetime.datetime(2026, 6, 22, tzinfo=datetime.UTC), + ) + assert a.generate_id() == b.generate_id() + assert a.generate_id().startswith("content_") + # Different content → different id. + c = TraceContentEvent(content_hash="sha256:other", role="user", content="hi") + assert c.generate_id() != a.generate_id() + + +class TestTraceSessionDedup: + def setup_method(self): + trace_session.reset() + + def teardown_method(self): + trace_session.reset() + + def test_first_emit_true_repeat_false(self): + assert trace_session.mark_emitted("run-1", "h1") is True + assert trace_session.mark_emitted("run-1", "h1") is False # already shipped + assert trace_session.mark_emitted("run-1", "h2") is True # new hash + + def test_runs_are_independent(self): + assert trace_session.mark_emitted("run-1", "h1") is True + assert trace_session.mark_emitted("run-2", "h1") is True # different run + + def test_lru_evicts_least_recently_used_run(self, monkeypatch: pytest.MonkeyPatch): + # Shrink the window so eviction is testable without _MAX_RUNS runs. + monkeypatch.setattr(trace_session, "_MAX_RUNS", 2) + trace_session.mark_emitted("run-1", "h1") + trace_session.mark_emitted("run-2", "h1") + # Touch run-1 so run-2 becomes the least-recently-used run. + trace_session.mark_emitted("run-1", "h2") + # A third run evicts the LRU run (run-2), keeping run-1. + trace_session.mark_emitted("run-3", "h1") + # run-1 is still tracked → its already-shipped hash stays deduped. + assert trace_session.mark_emitted("run-1", "h1") is False + # run-2 was evicted → its hash ships again as if a fresh run. + assert trace_session.mark_emitted("run-2", "h1") is True + + +class _FakeTraceEmitter: + """Stand-in for the trace emitter that records emitted events.""" + + def __init__(self) -> None: + self.events: list[object] = [] + + def emit(self, event: object) -> None: + self.events.append(event) + + +@pytest.fixture +def trace_on(monkeypatch: pytest.MonkeyPatch) -> Iterator[_FakeTraceEmitter]: + """Enable payload tracing and route emit_trace at a fake emitter.""" + from src.config import settings + from src.telemetry import emitter as emitter_mod + + monkeypatch.setattr(settings.TELEMETRY, "TRACE_PAYLOADS_ENABLED", True) + fake = _FakeTraceEmitter() + monkeypatch.setattr(emitter_mod, "_trace_emitter", fake) + trace_session.reset() + yield fake + trace_session.reset() + + +def _captured( + messages: list[dict[str, Any]], *, content: str = "answer", run: str = "r1" +) -> CapturedLLMCall: + from src.llm.types import LLMTelemetryContext + + return build_captured_call( + telemetry=LLMTelemetryContext( + workspace_name="ws", + call_purpose="dialectic.answer", + parent_category="dialectic", + run_id=run, + trace_id=run, + span_id=run, + iteration=1, + step_seq=1, + ), + transport="anthropic", + provider_label=None, + model="claude-x", + messages=messages, + tools=None, + tool_choice=None, + result=CompletionResult(content=content, finish_reason="stop"), + attempt=1, + was_fallback=False, + was_stream=False, + finish_reason="stop", + ) + + +class TestTraceExporter: + def test_refs_match_emitted_content(self, trace_on: _FakeTraceEmitter): + from src.telemetry.trace_exporter import TraceExporter + + call = _captured([{"role": "user", "content": "q"}]) + TraceExporter().export(call) + + traced = [e for e in trace_on.events if isinstance(e, LLMCallTracedEvent)] + contents = [e for e in trace_on.events if isinstance(e, TraceContentEvent)] + assert len(traced) == 1 + # input message + output content → two content events. + emitted_hashes = {c.content_hash for c in contents} + # Every input ref points at an emitted trace.content. + for ref in traced[0].input_message_refs: + assert ref in emitted_hashes + assert traced[0].output_content_ref in emitted_hashes + + def test_dedup_across_iterations(self, trace_on: _FakeTraceEmitter): + from src.telemetry.trace_exporter import TraceExporter + + exporter = TraceExporter() + shared = {"role": "user", "content": "system context"} + # Iteration 1: messages [shared]; iteration 2: [shared, follow-up]. + exporter.export(_captured([shared])) + before = sum(isinstance(e, TraceContentEvent) for e in trace_on.events) + exporter.export(_captured([shared, {"role": "user", "content": "more"}])) + after = sum(isinstance(e, TraceContentEvent) for e in trace_on.events) + # `shared` already shipped this run → only the new message (+ output if + # not already seen) emit again; `shared` is NOT re-emitted. + shared_hash = None + for e in trace_on.events: + if isinstance(e, TraceContentEvent) and e.content == "system context": + shared_hash = e.content_hash + emitted_shared = [ + e + for e in trace_on.events + if isinstance(e, TraceContentEvent) and e.content_hash == shared_hash + ] + assert len(emitted_shared) == 1 # shipped once across both iterations + assert after > before # the new message did ship + + def test_purpose_allowlist_filters( + self, trace_on: _FakeTraceEmitter, monkeypatch: pytest.MonkeyPatch + ): + from src.config import settings + from src.telemetry.trace_exporter import TraceExporter + + monkeypatch.setattr(settings.TELEMETRY, "TRACE_PURPOSES", ["summary.short"]) + TraceExporter().export(_captured([{"role": "user", "content": "q"}])) + # call_purpose is dialectic.answer, not in the allowlist → nothing emits. + assert trace_on.events == [] diff --git a/tests/utils/test_clients.py b/tests/utils/test_clients.py index 319e5f1f..49b2d75d 100644 --- a/tests/utils/test_clients.py +++ b/tests/utils/test_clients.py @@ -935,6 +935,7 @@ class TestMainLLMCallFunction: with ( patch.dict(CLIENTS, {"anthropic": mock_llm_client}), patch.object(settings, "LANGFUSE_PUBLIC_KEY", "test-public-key"), + patch.object(settings, "LANGFUSE_EXPORTER_MODE", "inline"), patch("langfuse.get_client", return_value=mock_langfuse_client), patch("langfuse.propagate_attributes", fake_propagate), ): @@ -1008,6 +1009,7 @@ class TestMainLLMCallFunction: with ( patch.dict(CLIENTS, {"anthropic": mock_llm_client}), patch.object(settings, "LANGFUSE_PUBLIC_KEY", "test-public-key"), + patch.object(settings, "LANGFUSE_EXPORTER_MODE", "inline"), patch("langfuse.get_client", return_value=mock_langfuse_client), patch("langfuse.propagate_attributes", fake_propagate), ):