diff --git a/CHANGELOG.md b/CHANGELOG.md index 0d2cac1..066f2f6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,20 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] ### Added +- **Trace/envelope `dims`**: flat `dict[str, str]` attributes on every envelope. + Pass trace-level dims via `chronicle.record(..., dims={...})`; they are copied + onto each span. Envelope-specific dims (e.g. `model_version`) merge on top. + File storage only for now (JSONL / fixture export). Lookup by dims belongs on + the shared control plane / dashboard, not in this library. +- **OTel-style nest parents**: boundaries open a span on the Context stack before + the body runs (`start_span` / `end_span`), so nested calls set + `parent_envelope_id` to the active parent (not the last finished envelope). + Optional debug helpers: `ExecutionGraph.to_otel_tree()` / + `to_otel_waterfall()` (product UI stays shared with TokenOps / the plane). +- **Dev / CI extras**: `[dev]` installs `[otel]` (OpenTelemetry + OpenInference) + instead of full `[phoenix]`, so `arize-phoenix` is not pulled into pytest + collection (its pytest plugin has been crashing CI on Python 3.11). Use + `pip install agent-chronicle[phoenix]` when you want the Phoenix collector/UI. - **`CHRONICLE_ENABLED`**: set to `0` / `false` / `off` / `no` to turn off LIVE recording. `@boundary`, `wrap`, `wrap_llm`, `record()`, and `EnvelopeRecorder` become passthrough so an agent can be run with and without Chronicle. Replay is diff --git a/README.md b/README.md index f794b7f..5a41cb7 100644 --- a/README.md +++ b/README.md @@ -30,15 +30,16 @@ walks you from install to a committed regression test. **[Why](#why-chronicle) · [Quick start](#quick-start) · [Cut-point replay](#cut-point-replay) · [Recording](#recording-entry-points) · [Verification](#verification-layers) · [Compare](#how-chronicle-compares) · [Demos](#demos) · [FAQ](#faq) · [Roadmap](#roadmap)**
-Key terms (boundary, Envelope, trace, fixture, stub, live, cut-point) +Key terms (boundary, Envelope, trace, dims, fixture, stub, live, cut-point)
| Term | What it means | |---|---| -| **Boundary** | A decision point you mark: an LLM call, a tool call, or a routing choice. You choose which functions are boundaries. | -| **Envelope** | The immutable record of one boundary crossing: its input, its output, and metadata. It records I/O, not the side effects inside the function. | -| **Trace** | One whole run, as an ordered set of Envelopes. | +| **Boundary** | A decision **node** you mark: an LLM call, a tool call, or a routing choice — not the whole agent process. Orchestration stays plain code. | +| **Envelope** | The immutable record of one boundary crossing: its input, its output, and metadata. It records I/O, not the side effects inside the function. OTel: one **span**. | +| **Trace** | One whole run (typically one message turn), as an ordered set of Envelopes sharing a `trace_id`. | +| **Dims** | Flat `dict[str, str]` attributes on each envelope (e.g. `session_id`, `message_id`). Trace-level dims are passed into `record(...)` and copied onto every span. | | **Fixture** | A trace committed to git under `fixtures/traces/`. Your permanent, replayable incident. | | **Stub** | On replay, hand back a boundary's recorded output *without running its code*. | | **Live** | Run the boundary's real code (to record it, or, on replay, to run your new code). | @@ -93,6 +94,7 @@ deterministic. | Input state | Assembled prompt, graph state, retrieved context chunks | | Action / result | Structured tool calls and model completion | | Graph linkage | `parent_envelope_id`, `sequence`, `invocation_index` for retries | +| Dims | Flat `dict[str, str]` (trace-level via `record(..., dims=...)`, plus span attrs like `model_version`) | ## Install @@ -122,26 +124,32 @@ client.chat.completions.create(model="gpt-4o", messages=[...]) # recorded > boundary (a real file delete, an API POST, a DB write) are **not** captured, so on > replay a stubbed boundary returns the recorded output without firing them again. -**2. Or mark your own boundaries** with `@boundary`, for exact control over what counts -as an LLM, tool, or routing decision: +**2. Or mark your own boundaries** with `@boundary` on **decision nodes** (LLM, +tool, router) — not on the full agent runner. Nested calls inside a node span +parent to that node automatically (OTel-style `parent_span_id`): ```python from chronicle import boundary -@boundary("agent", kind="llm") -def agent_plan(state: dict) -> dict: +@boundary("planner", kind="llm") +def planner(task: str) -> dict: ... @boundary("delete_file", kind="tool") def delete_file(path: str, environment: str) -> dict: ... + +def run_agent(task: str) -> dict: # plain orchestration — no @boundary + plan = planner(task) + ... ``` `@boundary` works on `async def` too, and it is **transparent**: it never changes what your function returns or raises. A bare `@boundary` records the call by argument name, so extractors are an optional way to trim payloads, never a requirement. -**3. Record a run and freeze it as a committed fixture** in one block: +**3. Record a run** (optional product dims for later lookup) **and freeze it as a +committed fixture** in one block: ```python import chronicle @@ -150,10 +158,29 @@ with chronicle.record( "incident-001", store=".chronicle/runs/incident.jsonl", # raw run, gitignored export="fixtures/traces/incident-001/", # the committed fixture you keep + dims={ # flat string attrs on every envelope + "session_id": "sess_abc", + "message_id": "msg_042", # one trace ≈ one message turn + "user_id": "u1", + }, ): run_agent(...) ``` +### Attribution (session / message) + +Chronicle does **not** own chat history or Session↔Message storage. Pass ids as +`dims` so a control plane or dashboard can resolve feedback → trace later: + +| Scenario | Dims to pass | +|---|---| +| Multi-turn chat | Same `session_id`, new `message_id` (and new `trace_id`) per user turn | +| Single-shot / S2S | `session_id` (and optional `caller_id` / `caller_type`) | + +One Chronicle **trace** is one agent run — typically one message turn. Nested LLM +and tool envelopes under a graph node share that `trace_id` and parent to the +active node span. + ### Which entry point should I record with? Pick by what you already have. All four produce the **same Envelopes** and replay the @@ -430,8 +457,9 @@ with chronicle.record("run-1") as session: run_agent(...) ``` -Call it inside the `record` block, or pass `session=`. Needs the OTel extra -(`pip install agent-chronicle[phoenix]`); the base install imports no OpenTelemetry. +Call it inside the `record` block, or pass `session=`. Needs the OTel SDK +(`pip install agent-chronicle[otel]`, or `[phoenix]` if you also want the Phoenix +collector/UI). The base install imports no OpenTelemetry.
@@ -512,11 +540,25 @@ plugin, and a docs site). Shape priorities in
What counts as a boundary, and how many should I add? -A boundary is any decision point you want to be able to freeze and replay: an LLM call, -a tool or function call, or a routing choice. You do not need to wrap everything. Start -with the calls you would actually assert on in a test: the model call that decides an -action, and each tool that has a real effect (a write, a payment, a delete). A boundary -you never stub or assert on just adds an envelope, so add them where a test would look. +A boundary is any **decision node** you want to freeze and replay: an LLM call, a +tool call, or a routing choice. Mark those nodes — not the whole `run_agent` +process. Orchestration stays plain code; if a graph node calls an LLM and a tool +while its span is open, those children parent under the node automatically. + +Start with the calls you would assert on in a test: the model call that decides an +action, and each tool that has a real effect (a write, a payment, a delete). A +boundary you never stub or assert on just adds an envelope, so add them where a +test would look. +
+ +
+How do I correlate a production session / message with a Chronicle trace? + +Pass flat string `dims` into `chronicle.record(...)`, e.g. `session_id` and +`message_id`. They are copied onto every envelope in that run. One trace ≈ one +message turn; multi-turn chats reuse `session_id` and mint a new `message_id` (and +trace) per turn. Chronicle does not store chat history — your app or dashboard maps +feedback to those ids, then to `trace_id`.
diff --git a/chronicle/api.py b/chronicle/api.py index df4ee2d..5ee793b 100644 --- a/chronicle/api.py +++ b/chronicle/api.py @@ -28,6 +28,7 @@ def record( redactors: list[Callable[[str], str]] | None = None, export: str | Path | None = None, retain_envelopes: bool = True, + dims: dict[str, str] | None = None, ) -> Iterator[ChronicleSession]: """Record a run in one block. @@ -39,6 +40,7 @@ def record( "incident-001", store=".chronicle/runs/incident.jsonl", export="fixtures/traces/incident-001/", + dims={"session_id": "sess_abc", "user_id": "u1"}, ) as session: run_agent(...) @@ -48,6 +50,9 @@ def record( Set ``retain_envelopes=False`` when you only need the store write (skips the in-session list; ``export_trace`` will be empty). + + ``dims`` are trace-level flat string attributes copied onto every recorded + envelope (OTel-style resource/span attributes). """ session = reset_session() if not is_enabled(): @@ -65,7 +70,7 @@ def record( if redactors is not None: session.redactors = redactors session.retain_envelopes = retain_envelopes - session.begin_trace(trace_id) + session.begin_trace(trace_id, dims=dims) try: yield session finally: diff --git a/chronicle/boundary.py b/chronicle/boundary.py index 37238db..68b4a7c 100644 --- a/chronicle/boundary.py +++ b/chronicle/boundary.py @@ -210,15 +210,24 @@ def _record_call( ): input_state = _capture_input(fn, args, kwargs, extract_input, cached_sig) call_kwargs, entered = _apply_on_enter(session, boundary_id, kind, input_state, kwargs) + # Open the span before the body so nested boundaries parent here (OTel Context). + span_id, parent_id = session.start_span() try: try: result = fn(*args, **call_kwargs) except Exception as exc: - _record_failure(session, boundary_id, kind, input_state, exc) + _record_failure( + session, boundary_id, kind, input_state, exc, + envelope_id=span_id, parent_envelope_id=parent_id, + ) raise - _record_success(session, boundary_id, kind, input_state, result, extract_result, extract_metadata) + _record_success( + session, boundary_id, kind, input_state, result, extract_result, extract_metadata, + envelope_id=span_id, parent_envelope_id=parent_id, + ) return result finally: + session.end_span() _run_on_leave(session, boundary_id, kind, input_state, entered) @@ -228,19 +237,32 @@ async def _record_call_async( ): input_state = _capture_input(fn, args, kwargs, extract_input, cached_sig) call_kwargs, entered = _apply_on_enter(session, boundary_id, kind, input_state, kwargs) + span_id, parent_id = session.start_span() try: try: result = await fn(*args, **call_kwargs) except Exception as exc: - _record_failure(session, boundary_id, kind, input_state, exc) + _record_failure( + session, boundary_id, kind, input_state, exc, + envelope_id=span_id, parent_envelope_id=parent_id, + ) raise - _record_success(session, boundary_id, kind, input_state, result, extract_result, extract_metadata) + _record_success( + session, boundary_id, kind, input_state, result, extract_result, extract_metadata, + envelope_id=span_id, parent_envelope_id=parent_id, + ) return result finally: + session.end_span() _run_on_leave(session, boundary_id, kind, input_state, entered) -def _record_success(session, boundary_id, kind, input_state, result, extract_result, extract_metadata): +def _record_success( + session, boundary_id, kind, input_state, result, extract_result, extract_metadata, + *, + envelope_id: str | None = None, + parent_envelope_id: str | None = None, +): """Record the envelope, then notify observers. Never touches the return value.""" recorded = extract_result(result) if extract_result else result action_result = result_to_action_result(recorded, kind) @@ -248,19 +270,28 @@ def _record_success(session, boundary_id, kind, input_state, result, extract_res session.record_envelope( boundary_id, kind, input_state, action_result, model_version=model_version, sampling_params=sampling_params, + envelope_id=envelope_id, parent_envelope_id=parent_envelope_id, ) if session.on_crossing is not None: session.on_crossing(boundary_id, kind, input_state, result) -def _record_failure(session, boundary_id, kind, input_state, exc): +def _record_failure( + session, boundary_id, kind, input_state, exc, + *, + envelope_id: str | None = None, + parent_envelope_id: str | None = None, +): """Record a failed crossing so incidents that raise are still reproducible.""" action_result = ActionResult( error=str(exc), error_type=type(exc).__name__, finish_reason="error", ) - session.record_envelope(boundary_id, kind, input_state, action_result) + session.record_envelope( + boundary_id, kind, input_state, action_result, + envelope_id=envelope_id, parent_envelope_id=parent_envelope_id, + ) def _call_metadata(result, kind, extract_metadata): diff --git a/chronicle/envelope/schema.py b/chronicle/envelope/schema.py index 511e6dd..e9c8413 100644 --- a/chronicle/envelope/schema.py +++ b/chronicle/envelope/schema.py @@ -95,6 +95,11 @@ class Envelope(BaseModel): Every envelope captures contextual metadata, input state, and action/result at the intersection of agent nodes — the "flight data" of the agent. + + OTel mapping: ``trace_id`` is the Trace; ``envelope_id`` is the Span id; + ``parent_envelope_id`` is ``parent_span_id``. ``dims`` are flat string + attributes (trace-level dims are copied onto every span at record time; + envelope-level dims are span-specific). """ schema_version: str = "1.0" @@ -105,15 +110,30 @@ class Envelope(BaseModel): parent_envelope_id: str | None = None sequence: int = 0 invocation_index: int = 1 + # End time (when the envelope was written). Prefer ``started_at`` for span start. timestamp: datetime = Field(default_factory=lambda: datetime.now(timezone.utc)) + # Span start (OTel). None on pre-nest fixtures; waterfall falls back to timestamp. + started_at: datetime | None = None metadata: ContextMetadata input_state: InputState action_result: ActionResult + # Flat string→string attributes (OTel-style). Missing on pre-0.4 fixtures. + dims: dict[str, str] = Field(default_factory=dict) @property def boundary_id(self) -> str: return self.node_id + @property + def span_id(self) -> str: + """OTel alias for ``envelope_id``.""" + return self.envelope_id + + @property + def parent_span_id(self) -> str | None: + """OTel alias for ``parent_envelope_id``.""" + return self.parent_envelope_id + @field_validator("timestamp", mode="before") @classmethod def _ensure_utc(cls, v: datetime | str) -> datetime: diff --git a/chronicle/execution_graph.py b/chronicle/execution_graph.py index 92a5d63..1628fcb 100644 --- a/chronicle/execution_graph.py +++ b/chronicle/execution_graph.py @@ -4,6 +4,7 @@ import json from dataclasses import dataclass, field +from datetime import datetime from pathlib import Path from chronicle.envelope.schema import Envelope @@ -99,6 +100,8 @@ def save(self, directory: str | Path) -> None: graph_json = { "trace_id": self.trace_id, + "dims": self.dims, + "spans": node_entries, # OTel name; ``nodes`` kept for back-compat "nodes": node_entries, "edges": edges, "roots": self.root_ids, @@ -122,6 +125,19 @@ def envelope(self, boundary_id: str, invocation_index: int) -> Envelope: raise KeyError(f"No envelope for {boundary_id} invocation {invocation_index}") return matches[0] + @property + def dims(self) -> dict[str, str]: + """Trace-level dims: keys shared by every span (minus span-only stamps).""" + timelines = self.timeline() + if not timelines: + return {} + shared = dict(timelines[0].dims) + for env in timelines[1:]: + shared = {k: v for k, v in shared.items() if env.dims.get(k) == v} + for key in ("boundary_kind", "node_id", "model_version"): + shared.pop(key, None) + return shared + def to_mermaid(self) -> str: lines = ["graph TD"] for node in self.timeline(): @@ -143,24 +159,150 @@ def to_mermaid(self) -> str: return "\n".join(lines) def to_ascii(self) -> str: - lines = [f"Trace: {self.trace_id}", ""] - for node in self.timeline(): - indent = " " if node.parent_envelope_id else "" - env = node - action = "" - if env.action_result.tool_calls: - tc = env.action_result.tool_calls[0] - action = f" → tool_call({tc.name})" - elif env.action_result.raw_response: - action = f" → {env.action_result.raw_response}" - elif env.action_result.completion: - action = f" → {env.action_result.completion[:50]}" - lines.append( - f"{indent}[{env.sequence}] {env.node_id}#{env.invocation_index}" - f" ({env.boundary_kind}){action}" - ) + """OTel-style nested span tree (trace_id / span_id / parent_span_id).""" + return self.to_otel_tree() + + def to_otel_tree(self) -> str: + """Render the run as an OpenTelemetry-style Trace → Spans tree.""" + lines = [f"Trace: {self.trace_id}"] + trace_dims = self.dims + if trace_dims: + dim_str = " ".join(f"{k}={v}" for k, v in sorted(trace_dims.items())) + lines.append(f" resource/dims: {dim_str}") + lines.append("") + + children: dict[str | None, list[Envelope]] = {} + for env in self.timeline(): + children.setdefault(env.parent_envelope_id, []).append(env) + + def walk(parent_key: str | None, prefix: str) -> None: + siblings = children.get(parent_key, []) + for i, env in enumerate(siblings): + last = i == len(siblings) - 1 + branch = "└─" if last else "├─" + child_prefix = f"{prefix}{' ' if last else '│ '}" + span_short = env.span_id[:8] + parent_short = env.parent_span_id[:8] if env.parent_span_id else "—" + lines.append( + f"{prefix}{branch} {env.node_id}#{env.invocation_index} " + f"({env.boundary_kind}) span={span_short} parent={parent_short}" + ) + span_dims = { + k: v + for k, v in env.dims.items() + if k not in trace_dims and k not in ("boundary_kind", "node_id") + } + if span_dims: + dim_str = " ".join(f"{k}={v}" for k, v in sorted(span_dims.items())) + lines.append(f"{child_prefix}attrs: {dim_str}") + walk(env.envelope_id, child_prefix) + + if None in children or not self.timeline(): + walk(None, "") + else: + # Orphan parents: flat fallback. + for env in self.timeline(): + parent_short = (env.parent_span_id or "—")[:8] + lines.append( + f"- {env.node_id}#{env.invocation_index} ({env.boundary_kind}) " + f"span={env.span_id[:8]} parent={parent_short}" + ) + return "\n".join(lines) + def to_otel_waterfall(self, *, width: int = 48) -> str: + """Render an OpenTelemetry-style timeline waterfall (nested bars over time). + + Each row is a span; indentation follows parent→child. The bar covers + ``started_at`` → ``timestamp`` (end). Missing ``started_at`` falls back + to reconstructing from children / end time. + """ + envelopes = self.timeline() + if not envelopes: + return f"Trace: {self.trace_id}\n(no spans)" + + # Resolve [start, end] per span. Parent opens before children and closes after. + intervals: dict[str, tuple[datetime, datetime]] = {} + for env in envelopes: + end = env.timestamp + start = env.started_at or end + intervals[env.envelope_id] = (start, end) + + # Expand parents to enclose children (OTel parent fully wraps nested work). + children: dict[str | None, list[Envelope]] = {} + for env in envelopes: + children.setdefault(env.parent_envelope_id, []).append(env) + + def enclose(eid: str) -> tuple[datetime, datetime]: + start, end = intervals[eid] + for child in children.get(eid, []): + c_start, c_end = enclose(child.envelope_id) + if c_start < start: + start = c_start + if c_end > end: + end = c_end + intervals[eid] = (start, end) + return start, end + + for root in children.get(None, []): + enclose(root.envelope_id) + + t0 = min(s for s, _ in intervals.values()) + t1 = max(e for _, e in intervals.values()) + total_ms = max((t1 - t0).total_seconds() * 1000.0, 1.0) + + def col(dt: datetime) -> int: + ms = (dt - t0).total_seconds() * 1000.0 + return max(0, min(width - 1, int(round(ms / total_ms * (width - 1))))) + + lines = [ + f"Trace: {self.trace_id}", + f" total: {total_ms:.1f}ms [0ms ──► {total_ms:.1f}ms]", + ] + trace_dims = self.dims + if trace_dims: + dim_str = " ".join(f"{k}={v}" for k, v in sorted(trace_dims.items())) + lines.append(f" resource/dims: {dim_str}") + lines.append("") + label_w = max( + (len(f"{e.node_id}#{e.invocation_index}") + depth * 2 for depth, e in + self._waterfall_rows(children)), + default=12, + ) + label_w = min(max(label_w, 16), 28) + + def render(parent_key: str | None, depth: int) -> None: + for env in children.get(parent_key, []): + start, end = intervals[env.envelope_id] + left = col(start) + right = col(end) + if right <= left: + right = min(width, left + 1) + bar = " " * left + "█" * (right - left) + bar = bar.ljust(width) + dur_ms = (end - start).total_seconds() * 1000.0 + name = f"{' ' * depth}{env.node_id}#{env.invocation_index}" + lines.append( + f"{name:<{label_w}} {bar} {dur_ms:6.1f}ms {env.boundary_kind}" + ) + render(env.envelope_id, depth + 1) + + render(None, 0) + # Time axis + lines.append(f"{'':<{label_w}} {'└' + '─' * (width - 2) + '┘'}") + lines.append(f"{'':<{label_w}} 0ms{' ' * (width - 10)}{total_ms:.0f}ms") + return "\n".join(lines) + + def _waterfall_rows( + self, children: dict[str | None, list[Envelope]] + ): + def walk(parent_key: str | None, depth: int): + for env in children.get(parent_key, []): + yield depth, env + yield from walk(env.envelope_id, depth + 1) + + yield from walk(None, 0) + @property def initial_state(self) -> dict: if not self.timeline(): diff --git a/chronicle/otel.py b/chronicle/otel.py index 59049f9..7ebbf87 100644 --- a/chronicle/otel.py +++ b/chronicle/otel.py @@ -13,6 +13,10 @@ ``session=`` explicitly. Requires the OpenTelemetry SDK and OpenInference conventions: ``pip install agent-chronicle[phoenix]``. Nothing here is imported by ``import chronicle``, so the base install needs neither package. + +Spans start when the Chronicle nest stack opens (``start_span``), so children can parent +to an already-active OTel span — matching OTel Context semantics even though the +Envelope is written after the boundary body returns. """ from __future__ import annotations @@ -95,6 +99,8 @@ def envelope_span_attributes(envelope: Envelope) -> dict[str, Any]: attributes[S.LLM_TOKEN_COUNT_COMPLETION] = int(completion) if envelope.boundary_kind == "tool": attributes[S.TOOL_NAME] = envelope.node_id + for key, value in (envelope.dims or {}).items(): + attributes[f"chronicle.dims.{key}"] = value return attributes @@ -105,30 +111,57 @@ def instrument_otel( ) -> Callable[[], None]: """Emit one OpenTelemetry span per recorded boundary crossing. - Attaches to ``session`` (default: the active session) via its ``on_record`` hook. - Spans nest by the run's parent linkage and carry OpenInference attributes. Returns a - callable that removes the instrumentation. + Spans open on ``session.start_span`` (so nested work parents correctly) and close + on ``on_record`` once envelope attributes are known. Returns a callable that + removes the instrumentation. """ trace = _require_trace() tracer = tracer or trace.get_tracer("chronicle") active = session or get_session() - spans: dict[str, Any] = {} # envelope_id -> span, for parent linkage + spans: dict[str, Any] = {} # envelope_id -> live OTel span + original_start = active.start_span + original_end = active.end_span + previous_on_record = active.on_record + + def start_span() -> tuple[str, str | None]: + span_id, parent_id = original_start() + parent = spans.get(parent_id) if parent_id else None + context = trace.set_span_in_context(parent) if parent is not None else None + # Name is finalized in on_record once the boundary id is known. + spans[span_id] = tracer.start_span("chronicle.boundary", context=context) + return span_id, parent_id + + def end_span() -> None: + original_end() def on_record(envelope: Envelope) -> None: - parent = spans.get(envelope.parent_envelope_id) if envelope.parent_envelope_id else None - context = trace.set_span_in_context(parent) if parent is not None else None - span = tracer.start_span(envelope.node_id, context=context) + span = spans.get(envelope.envelope_id) + if span is None: + # Caller recorded without start_span (legacy path): create + end now. + parent = spans.get(envelope.parent_envelope_id) if envelope.parent_envelope_id else None + context = trace.set_span_in_context(parent) if parent is not None else None + span = tracer.start_span(envelope.node_id, context=context) + spans[envelope.envelope_id] = span + else: + span.update_name(envelope.node_id) for key, value in envelope_span_attributes(envelope).items(): span.set_attribute(key, value) if envelope.action_result.error: span.set_status(trace.Status(trace.StatusCode.ERROR, envelope.action_result.error)) span.end() - spans[envelope.envelope_id] = span + if previous_on_record is not None: + previous_on_record(envelope) + active.start_span = start_span # type: ignore[method-assign] + active.end_span = end_span # type: ignore[method-assign] active.on_record = on_record def uninstrument() -> None: + if active.start_span is start_span: + active.start_span = original_start # type: ignore[method-assign] + if active.end_span is end_span: + active.end_span = original_end # type: ignore[method-assign] if active.on_record is on_record: - active.on_record = None + active.on_record = previous_on_record return uninstrument diff --git a/chronicle/session.py b/chronicle/session.py index 8e1ef96..560c3f9 100644 --- a/chronicle/session.py +++ b/chronicle/session.py @@ -28,6 +28,8 @@ from chronicle.execution_graph import ExecutionGraph _envelope_stack: ContextVar[list[str]] = ContextVar("chronicle_envelope_stack", default=[]) +# Sentinel so record_envelope can accept parent_envelope_id=None for root spans. +_PARENT_UNSET = object() class SessionMode(str, Enum): @@ -75,6 +77,8 @@ class ChronicleSession: # When False, envelopes are written to ``store`` only and not kept on the # session (``export_trace`` will be empty). Cuts memory traffic on hot paths. retain_envelopes: bool = True + # Trace-level flat string→string attributes (copied onto every envelope). + dims: dict[str, str] = field(default_factory=dict) _sequence: int = 0 _invocation_counts: dict[str, int] = field(default_factory=dict) @@ -84,12 +88,20 @@ class ChronicleSession: _captured_results: dict[tuple[str, int], Any] = field(default_factory=dict) _recorded_envelopes: list[Envelope] = field(default_factory=list) _last_envelope_id: str | None = None + _span_started_at: dict[str, datetime] = field(default_factory=dict) - def begin_trace(self, trace_id: str | None = None) -> str: + def begin_trace( + self, + trace_id: str | None = None, + *, + dims: dict[str, str] | None = None, + ) -> str: if trace_id: self.trace_id = trace_id else: self.trace_id = str(uuid.uuid4()) + if dims is not None: + self.dims = {str(k): str(v) for k, v in dims.items()} self._sequence = 0 self._invocation_counts.clear() self._replay_cursor.clear() @@ -98,9 +110,26 @@ def begin_trace(self, trace_id: str | None = None) -> str: self._captured_results.clear() self._recorded_envelopes.clear() self._last_envelope_id = None + self._span_started_at.clear() _envelope_stack.set([]) return self.trace_id + def start_span(self) -> tuple[str, str | None]: + """Allocate a span id and push it as the active parent (OTel Context). + + Returns ``(span_id, parent_span_id)``. Nested boundaries that start while + this span is active parent to ``span_id``. Call ``end_span`` in a finally. + """ + parent_id = self.current_parent_id() + span_id = str(uuid.uuid4()) + self._span_started_at[span_id] = datetime.now(timezone.utc) + self._push_envelope(span_id) + return span_id, parent_id + + def end_span(self) -> None: + """Pop the active span from the nest stack.""" + self._pop_envelope() + def enable_replay(self, plan: ReplayPlan | None = None) -> None: self.mode = SessionMode.REPLAY self.replay_plan = plan or ReplayPlan() @@ -152,16 +181,45 @@ def record_envelope( model_version: str | None = None, sampling_params: SamplingParams | None = None, tool_schemas: list[ToolSchema] | None = None, + envelope_id: str | None = None, + parent_envelope_id: Any = _PARENT_UNSET, + dims: dict[str, str] | None = None, ) -> Envelope: invocation_index = self.next_invocation(boundary_id) sequence = self.next_sequence() - parent_id = self._last_envelope_id + # Prefer explicit ids from start_span (OTel Context nesting). Fall back to + # linear last-finished only when the caller did not open a span. + # Important: parent_envelope_id=None means root (no parent); only the + # sentinel means "compute parent for me". + if envelope_id is None: + envelope_id = str(uuid.uuid4()) + if parent_envelope_id is _PARENT_UNSET: + # If this id is already on the stack (start_span), parent is below it. + stack = _envelope_stack.get() + if stack and stack[-1] == envelope_id and len(stack) >= 2: + parent_id = stack[-2] + elif stack and stack[-1] != envelope_id: + parent_id = stack[-1] + else: + parent_id = self._last_envelope_id + else: + parent_id = parent_envelope_id + + resolved_model = model_version or self.model_version + # Trace dims first; envelope dims override. Promote common span attrs. + merged_dims = {str(k): str(v) for k, v in self.dims.items()} + if resolved_model and resolved_model != "unknown": + merged_dims.setdefault("model_version", str(resolved_model)) + merged_dims.setdefault("boundary_kind", kind) + merged_dims.setdefault("node_id", boundary_id) + if dims: + merged_dims.update({str(k): str(v) for k, v in dims.items()}) # model_construct: fields are produced by Chronicle itself; skip pydantic # validation on the hot LIVE path. envelope = Envelope.model_construct( schema_version="1.0", - envelope_id=str(uuid.uuid4()), + envelope_id=envelope_id, trace_id=self.trace_id, node_id=boundary_id, boundary_kind=kind, @@ -169,10 +227,11 @@ def record_envelope( sequence=sequence, invocation_index=invocation_index, timestamp=datetime.now(timezone.utc), + started_at=self._span_started_at.pop(envelope_id, None), metadata=ContextMetadata.model_construct( # Prefer what the call actually used; fall back to the session # default only when the boundary surfaced no real metadata. - model_version=model_version or self.model_version, + model_version=resolved_model, build_id=self.build_id, sampling_params=sampling_params or SamplingParams.model_construct( temperature=None, top_p=None, max_tokens=None, seed=None, extra={}, @@ -185,6 +244,7 @@ def record_envelope( ), input_state=input_state, action_result=action_result, + dims=merged_dims, ) if self.redactors: @@ -192,15 +252,11 @@ def record_envelope( envelope = apply_redactors(envelope, self.redactors) - self._push_envelope(envelope.envelope_id) - try: - if self.retain_envelopes: - self._recorded_envelopes.append(envelope) - self._last_envelope_id = envelope.envelope_id - if self.store is not None: - self.store.append(envelope) - finally: - self._pop_envelope() + if self.retain_envelopes: + self._recorded_envelopes.append(envelope) + self._last_envelope_id = envelope.envelope_id + if self.store is not None: + self.store.append(envelope) self._call_log.append( CallRecord(boundary_id, invocation_index, "record", envelope.envelope_id) @@ -245,6 +301,11 @@ def invocation_count(self, boundary_id: str) -> int: def call_log(self) -> list[CallRecord]: return list(self._call_log) + @property + def envelopes(self) -> list[Envelope]: + """Recorded envelopes for this trace (empty when ``retain_envelopes=False``).""" + return list(self._recorded_envelopes) + def export_trace(self, directory: str | Path) -> Path: from chronicle.execution_graph import ExecutionGraph diff --git a/chronicle/wrap.py b/chronicle/wrap.py index fd45d7e..7496750 100644 --- a/chronicle/wrap.py +++ b/chronicle/wrap.py @@ -82,9 +82,16 @@ async def async_wrapper(*args: Any, **kwargs: Any) -> Any: input_state = _input_state(kwargs) if session.mode is SessionMode.REPLAY and _should_stub(session, boundary_id): return _stub(session, boundary_id) - result = await create(*args, **kwargs) - _observe(session, boundary_id, input_state, result, kwargs) - return result + span_id, parent_id = session.start_span() + try: + result = await create(*args, **kwargs) + _observe( + session, boundary_id, input_state, result, kwargs, + envelope_id=span_id, parent_envelope_id=parent_id, + ) + return result + finally: + session.end_span() return async_wrapper @@ -99,9 +106,16 @@ def wrapper(*args: Any, **kwargs: Any) -> Any: input_state = _input_state(kwargs) if session.mode is SessionMode.REPLAY and _should_stub(session, boundary_id): return _stub(session, boundary_id) - result = create(*args, **kwargs) - _observe(session, boundary_id, input_state, result, kwargs) - return result + span_id, parent_id = session.start_span() + try: + result = create(*args, **kwargs) + _observe( + session, boundary_id, input_state, result, kwargs, + envelope_id=span_id, parent_envelope_id=parent_id, + ) + return result + finally: + session.end_span() return wrapper @@ -111,7 +125,12 @@ def _should_stub(session, boundary_id: str) -> bool: return session.replay_plan.should_stub(boundary_id, invocation_index) -def _observe(session, boundary_id, input_state, response, request_kwargs): +def _observe( + session, boundary_id, input_state, response, request_kwargs, + *, + envelope_id: str | None = None, + parent_envelope_id: str | None = None, +): """Record in LIVE, or capture as a live cut-point in REPLAY. Never mutates the response; the caller always gets the real object.""" completion, model, usage = _extract(response) @@ -130,6 +149,7 @@ def _observe(session, boundary_id, input_state, response, request_kwargs): session.record_envelope( boundary_id, "llm", input_state, action, model_version=model, sampling_params=sampling_params_from(request_kwargs), + envelope_id=envelope_id, parent_envelope_id=parent_envelope_id, ) if session.on_crossing is not None: session.on_crossing(boundary_id, "llm", input_state, response) diff --git a/docs/onboarding.md b/docs/onboarding.md index 154370e..7b59011 100644 --- a/docs/onboarding.md +++ b/docs/onboarding.md @@ -35,13 +35,18 @@ Requires Python 3.10+. Nothing else to configure. ## Step 2: Mark your boundaries You mark boundaries because only you know which functions are the meaningful -decision points. There are three ways; use whichever fits your code. +**decision nodes**. Mark those — not the whole `run_agent` process. There are +three ways; use whichever fits your code. | Your setup | Do you mark manually? | How | |---|---|---| | The **LLM call** (any framework) | No | `client = chronicle.wrap(OpenAI())` | | Your **tool / step functions** (plain Python) | Yes, one decorator each | `@boundary("refund", kind="tool")` | -| **LangGraph** | No | `chronicle.instrument_langgraph(nodes)` | +| **LangGraph** nodes | No | `chronicle.instrument_langgraph(nodes)` | +| Top-level `run_agent(...)` | **No** | Leave orchestration unmarked | + +Nested LLM/tool calls inside a graph-node boundary parent to that node +automatically (OTel-style `parent_span_id`). **a) The LLM call: wrap the client where you create it.** No decorators: @@ -127,19 +132,26 @@ one crossing plus context; it does not capture the inside of your function. ## Step 3: Record a run -Wrap the run you want to capture: +Wrap the run you want to capture. Pass product ids as flat `dims` when you have +them (one trace ≈ one message turn; Chronicle does not own chat history): ```python with chronicle.record( "incident-001", store=".chronicle/runs/incident.jsonl", # raw log (optional) export="fixtures/traces/incident-001/", # the committed fixture + dims={ + "session_id": "sess_abc", + "message_id": "msg_042", + }, ): run_agent(...) # runs normally, and is recorded ``` - `store=` writes the raw run as it happens (survives a crash). Optional. - `export=` writes the trace you keep and commit. This is what makes a test. +- `dims=` are copied onto every envelope so a dashboard can resolve + session/message → trace later. --- diff --git a/examples/otel_tree_mas1.py b/examples/otel_tree_mas1.py new file mode 100644 index 0000000..8df6e55 --- /dev/null +++ b/examples/otel_tree_mas1.py @@ -0,0 +1,153 @@ +#!/usr/bin/env python3 +"""Record testbench MAS-1 (orchestrator-workers) and print an OTel-style span tree. + +Uses the local editable Chronicle + stub LLM (no API keys). LangGraph nodes are +instrumented as chain spans; each node's LLM call nests underneath (parent_span_id). + + PYTHONPATH=/Users/susheemkoul/Desktop/testbench/src \\ + python examples/otel_tree_mas1.py +""" + +from __future__ import annotations + +import sys +from functools import partial +from pathlib import Path + +from langgraph.graph import END, StateGraph + +import chronicle +from chronicle import JsonlStore + +TESTBENCH_SRC = Path("/Users/susheemkoul/Desktop/testbench/src") +if str(TESTBENCH_SRC) not in sys.path: + sys.path.insert(0, str(TESTBENCH_SRC)) + +from testbench.core import NullSink, RunConfig # noqa: E402 +from testbench.core.llm import Message, ModelResponse, Usage # noqa: E402 +from testbench.core.stub import StubClient # noqa: E402 +from testbench.orchestrator_workers import workers # noqa: E402 +from testbench.orchestrator_workers.state import ResearchState # noqa: E402 + +OUT = Path(__file__).resolve().parents[1] / "outputs" / "mas1_otel_tree" +TASK = "What is token governance and why does it matter for agents?" + + +def _wrap_stub(client: StubClient): + """Chronicle-wrap StubClient.complete as an llm span.""" + + def dispatch(model: str, messages: list[Message], **kwargs): + return client.complete(model, messages, **kwargs) + + def extract_input(model, messages, **kwargs): + from chronicle.envelope.schema import InputState + + return InputState( + messages=[{"role": m.role, "content": m.content} for m in messages], + graph_state={"model": model}, + ) + + def extract_result(resp: ModelResponse): + return { + "content": resp.text, + "model": resp.model, + "usage": { + "prompt_tokens": resp.usage.input_tokens, + "completion_tokens": resp.usage.output_tokens, + }, + } + + def extract_metadata(resp): + if isinstance(resp, dict): + return {"model": resp.get("model")} + return {"model": getattr(resp, "model", None)} + + return chronicle.wrap_llm( + "llm", + dispatch, + extract_input=extract_input, + extract_result=extract_result, + extract_metadata=extract_metadata, + ) + + +class _InstrumentedClient: + """LLMClient whose complete() is Chronicle-wrapped.""" + + def __init__(self, complete): + self.complete = complete + + +def build_instrumented_graph(client, sink, cfg): + """Same MAS-1 wiring as testbench, with every node as a Chronicle boundary.""" + raw = { + "supervisor": partial(workers.supervisor_node, client=client, sink=sink, cfg=cfg), + "researcher": partial(workers.researcher_node, client=client, sink=sink, cfg=cfg), + "analyst": partial(workers.analyst_node, client=client, sink=sink, cfg=cfg), + "writer": partial(workers.writer_node, client=client, sink=sink, cfg=cfg), + } + nodes = chronicle.instrument_langgraph(raw, kind="custom") + + g = StateGraph(ResearchState) + for name, fn in nodes.items(): + g.add_node(name, fn) + g.set_entry_point("supervisor") + g.add_conditional_edges( + "supervisor", + workers.route, + {"researcher": "researcher", "analyst": "analyst", "writer": "writer", "FINISH": END}, + ) + for worker in ("researcher", "analyst", "writer"): + g.add_edge(worker, "supervisor") + return g.compile() + + +def main() -> None: + OUT.mkdir(parents=True, exist_ok=True) + store_path = OUT / "spans.jsonl" + if store_path.exists(): + store_path.unlink() + + stub = StubClient() + llm = _wrap_stub(stub) + client = _InstrumentedClient(llm) + sink = NullSink() + cfg = RunConfig() + + dims = { + "session_id": "sess_mas1_demo", + "message_id": "msg_001", + "user_id": "dev", + "workload": "mas1", + "mode": "stub", + } + + with chronicle.record( + "mas1-otel-tree", + store=JsonlStore(store_path), + dims=dims, + export=OUT / "trace", + ) as session: + graph = build_instrumented_graph(client, sink, cfg) + result = graph.invoke( + ResearchState( + task=TASK, plan="", research="", analysis="", brief="", next="" + ) + ) + + graph = chronicle.ExecutionGraph.from_envelopes(session.trace_id, session.envelopes) + tree = graph.to_otel_tree() + tree_path = OUT / "otel_tree.txt" + tree_path.write_text(tree + "\n", encoding="utf-8") + + print(tree) + print() + print(f"envelopes={len(session.envelopes)} jsonl={store_path}") + print(f"fixture={OUT / 'trace'} tree={tree_path}") + brief = (result or {}).get("brief") or "" + if brief: + print(f"brief={brief[:120]!r}") + + +if __name__ == "__main__": + main() diff --git a/fixtures/traces/parent-calls-subagent-twice/001-llm-1.json b/fixtures/traces/parent-calls-subagent-twice/001-llm-1.json new file mode 100644 index 0000000..035c8b3 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/001-llm-1.json @@ -0,0 +1,73 @@ +{ + "schema_version": "1.0", + "envelope_id": "fc9038f7-b52e-4c47-8aaf-afdf4761e3fb", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "llm", + "boundary_kind": "llm", + "parent_envelope_id": "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "sequence": 1, + "invocation_index": 1, + "timestamp": "2026-08-10T15:22:50.894808Z", + "started_at": "2026-08-10T15:22:50.852504Z", + "metadata": { + "model_version": "stub-researcher", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "llm", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [ + { + "role": "user", + "content": "pricing" + } + ], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "messages": [ + { + "role": "user", + "content": "pricing" + } + ], + "model": "stub-researcher" + } + }, + "action_result": { + "tool_calls": [ + { + "id": "call_1", + "name": "web_search", + "arguments": { + "q": "pricing" + } + } + ], + "completion": null, + "finish_reason": "tool_calls", + "token_usage": {}, + "raw_response": null, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "model_version": "stub-researcher", + "boundary_kind": "llm", + "node_id": "llm" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/002-web_search-1.json b/fixtures/traces/parent-calls-subagent-twice/002-web_search-1.json new file mode 100644 index 0000000..d3b0b2f --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/002-web_search-1.json @@ -0,0 +1,58 @@ +{ + "schema_version": "1.0", + "envelope_id": "694a02ce-574b-4435-acb6-d82ced786aa6", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "web_search", + "boundary_kind": "tool", + "parent_envelope_id": "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "sequence": 2, + "invocation_index": 1, + "timestamp": "2026-08-10T15:22:50.926832Z", + "started_at": "2026-08-10T15:22:50.895131Z", + "metadata": { + "model_version": "unknown", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "web_search", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "q": "pricing" + } + }, + "action_result": { + "tool_calls": [], + "completion": "{'results': ['doc about pricing'], 'q': 'pricing'}", + "finish_reason": null, + "token_usage": {}, + "raw_response": { + "results": [ + "doc about pricing" + ], + "q": "pricing" + }, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "boundary_kind": "tool", + "node_id": "web_search" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/003-researcher-1.json b/fixtures/traces/parent-calls-subagent-twice/003-researcher-1.json new file mode 100644 index 0000000..dd40514 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/003-researcher-1.json @@ -0,0 +1,53 @@ +{ + "schema_version": "1.0", + "envelope_id": "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "researcher", + "boundary_kind": "custom", + "parent_envelope_id": "0c707775-33af-4885-9d6d-ce23018b7036", + "sequence": 3, + "invocation_index": 1, + "timestamp": "2026-08-10T15:22:50.927009Z", + "started_at": "2026-08-10T15:22:50.852172Z", + "metadata": { + "model_version": "unknown", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "researcher", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "query": "pricing" + } + }, + "action_result": { + "tool_calls": [], + "completion": "findings:doc about pricing", + "finish_reason": null, + "token_usage": {}, + "raw_response": null, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "boundary_kind": "custom", + "node_id": "researcher" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/004-llm-2.json b/fixtures/traces/parent-calls-subagent-twice/004-llm-2.json new file mode 100644 index 0000000..5a825f6 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/004-llm-2.json @@ -0,0 +1,73 @@ +{ + "schema_version": "1.0", + "envelope_id": "ec8ab837-8412-45fd-b4e9-992e82135beb", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "llm", + "boundary_kind": "llm", + "parent_envelope_id": "26db5a61-3535-4790-887b-c621297b45ab", + "sequence": 4, + "invocation_index": 2, + "timestamp": "2026-08-10T15:22:50.983491Z", + "started_at": "2026-08-10T15:22:50.943009Z", + "metadata": { + "model_version": "stub-researcher", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "llm", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [ + { + "role": "user", + "content": "risks" + } + ], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "messages": [ + { + "role": "user", + "content": "risks" + } + ], + "model": "stub-researcher" + } + }, + "action_result": { + "tool_calls": [ + { + "id": "call_1", + "name": "web_search", + "arguments": { + "q": "risks" + } + } + ], + "completion": null, + "finish_reason": "tool_calls", + "token_usage": {}, + "raw_response": null, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "model_version": "stub-researcher", + "boundary_kind": "llm", + "node_id": "llm" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/005-web_search-2.json b/fixtures/traces/parent-calls-subagent-twice/005-web_search-2.json new file mode 100644 index 0000000..b7b1900 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/005-web_search-2.json @@ -0,0 +1,58 @@ +{ + "schema_version": "1.0", + "envelope_id": "745360a0-be78-488b-bd60-40c2698cbe06", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "web_search", + "boundary_kind": "tool", + "parent_envelope_id": "26db5a61-3535-4790-887b-c621297b45ab", + "sequence": 5, + "invocation_index": 2, + "timestamp": "2026-08-10T15:22:51.015002Z", + "started_at": "2026-08-10T15:22:50.984110Z", + "metadata": { + "model_version": "unknown", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "web_search", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "q": "risks" + } + }, + "action_result": { + "tool_calls": [], + "completion": "{'results': ['doc about risks'], 'q': 'risks'}", + "finish_reason": null, + "token_usage": {}, + "raw_response": { + "results": [ + "doc about risks" + ], + "q": "risks" + }, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "boundary_kind": "tool", + "node_id": "web_search" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/006-researcher-2.json b/fixtures/traces/parent-calls-subagent-twice/006-researcher-2.json new file mode 100644 index 0000000..62b6504 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/006-researcher-2.json @@ -0,0 +1,53 @@ +{ + "schema_version": "1.0", + "envelope_id": "26db5a61-3535-4790-887b-c621297b45ab", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "researcher", + "boundary_kind": "custom", + "parent_envelope_id": "0c707775-33af-4885-9d6d-ce23018b7036", + "sequence": 6, + "invocation_index": 2, + "timestamp": "2026-08-10T15:22:51.015155Z", + "started_at": "2026-08-10T15:22:50.942852Z", + "metadata": { + "model_version": "unknown", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "researcher", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "query": "risks" + } + }, + "action_result": { + "tool_calls": [], + "completion": "findings:doc about risks", + "finish_reason": null, + "token_usage": {}, + "raw_response": null, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "boundary_kind": "custom", + "node_id": "researcher" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/007-orchestrator-1.json b/fixtures/traces/parent-calls-subagent-twice/007-orchestrator-1.json new file mode 100644 index 0000000..9d383dc --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/007-orchestrator-1.json @@ -0,0 +1,60 @@ +{ + "schema_version": "1.0", + "envelope_id": "0c707775-33af-4885-9d6d-ce23018b7036", + "trace_id": "trace-parent-calls-subagent-twice", + "node_id": "orchestrator", + "boundary_kind": "custom", + "parent_envelope_id": null, + "sequence": 7, + "invocation_index": 1, + "timestamp": "2026-08-10T15:22:51.015268Z", + "started_at": "2026-08-10T15:22:50.850754Z", + "metadata": { + "model_version": "unknown", + "sampling_params": { + "temperature": null, + "top_p": null, + "max_tokens": null, + "seed": null, + "extra": {} + }, + "build_id": "dev-local", + "tool_schemas": [], + "framework": "chronicle.boundary", + "node_id": "orchestrator", + "trace_id": "trace-parent-calls-subagent-twice", + "extra": {} + }, + "input_state": { + "messages": [], + "system_prompt": null, + "rag_chunks": [], + "graph_state": { + "task": "compare vendors" + } + }, + "action_result": { + "tool_calls": [], + "completion": "{'task': 'compare vendors', 'research': ['findings:doc about pricing', 'findings:doc about risks'], 'completion': 'done'}", + "finish_reason": null, + "token_usage": {}, + "raw_response": { + "task": "compare vendors", + "research": [ + "findings:doc about pricing", + "findings:doc about risks" + ], + "completion": "done" + }, + "error": null, + "error_type": null + }, + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice", + "boundary_kind": "custom", + "node_id": "orchestrator" + } +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/graph.json b/fixtures/traces/parent-calls-subagent-twice/graph.json new file mode 100644 index 0000000..153a69b --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/graph.json @@ -0,0 +1,154 @@ +{ + "trace_id": "trace-parent-calls-subagent-twice", + "dims": { + "session_id": "sess_subagent_x2", + "message_id": "msg_042", + "user_id": "dev", + "scenario": "parent_calls_subagent_twice" + }, + "spans": [ + { + "envelope_id": "fc9038f7-b52e-4c47-8aaf-afdf4761e3fb", + "boundary_id": "llm", + "boundary_kind": "llm", + "invocation_index": 1, + "sequence": 1, + "fixture": "001-llm-1.json" + }, + { + "envelope_id": "694a02ce-574b-4435-acb6-d82ced786aa6", + "boundary_id": "web_search", + "boundary_kind": "tool", + "invocation_index": 1, + "sequence": 2, + "fixture": "002-web_search-1.json" + }, + { + "envelope_id": "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "boundary_id": "researcher", + "boundary_kind": "custom", + "invocation_index": 1, + "sequence": 3, + "fixture": "003-researcher-1.json" + }, + { + "envelope_id": "ec8ab837-8412-45fd-b4e9-992e82135beb", + "boundary_id": "llm", + "boundary_kind": "llm", + "invocation_index": 2, + "sequence": 4, + "fixture": "004-llm-2.json" + }, + { + "envelope_id": "745360a0-be78-488b-bd60-40c2698cbe06", + "boundary_id": "web_search", + "boundary_kind": "tool", + "invocation_index": 2, + "sequence": 5, + "fixture": "005-web_search-2.json" + }, + { + "envelope_id": "26db5a61-3535-4790-887b-c621297b45ab", + "boundary_id": "researcher", + "boundary_kind": "custom", + "invocation_index": 2, + "sequence": 6, + "fixture": "006-researcher-2.json" + }, + { + "envelope_id": "0c707775-33af-4885-9d6d-ce23018b7036", + "boundary_id": "orchestrator", + "boundary_kind": "custom", + "invocation_index": 1, + "sequence": 7, + "fixture": "007-orchestrator-1.json" + } + ], + "nodes": [ + { + "envelope_id": "fc9038f7-b52e-4c47-8aaf-afdf4761e3fb", + "boundary_id": "llm", + "boundary_kind": "llm", + "invocation_index": 1, + "sequence": 1, + "fixture": "001-llm-1.json" + }, + { + "envelope_id": "694a02ce-574b-4435-acb6-d82ced786aa6", + "boundary_id": "web_search", + "boundary_kind": "tool", + "invocation_index": 1, + "sequence": 2, + "fixture": "002-web_search-1.json" + }, + { + "envelope_id": "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "boundary_id": "researcher", + "boundary_kind": "custom", + "invocation_index": 1, + "sequence": 3, + "fixture": "003-researcher-1.json" + }, + { + "envelope_id": "ec8ab837-8412-45fd-b4e9-992e82135beb", + "boundary_id": "llm", + "boundary_kind": "llm", + "invocation_index": 2, + "sequence": 4, + "fixture": "004-llm-2.json" + }, + { + "envelope_id": "745360a0-be78-488b-bd60-40c2698cbe06", + "boundary_id": "web_search", + "boundary_kind": "tool", + "invocation_index": 2, + "sequence": 5, + "fixture": "005-web_search-2.json" + }, + { + "envelope_id": "26db5a61-3535-4790-887b-c621297b45ab", + "boundary_id": "researcher", + "boundary_kind": "custom", + "invocation_index": 2, + "sequence": 6, + "fixture": "006-researcher-2.json" + }, + { + "envelope_id": "0c707775-33af-4885-9d6d-ce23018b7036", + "boundary_id": "orchestrator", + "boundary_kind": "custom", + "invocation_index": 1, + "sequence": 7, + "fixture": "007-orchestrator-1.json" + } + ], + "edges": [ + [ + "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "fc9038f7-b52e-4c47-8aaf-afdf4761e3fb" + ], + [ + "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1", + "694a02ce-574b-4435-acb6-d82ced786aa6" + ], + [ + "0c707775-33af-4885-9d6d-ce23018b7036", + "5feec2ff-ddef-46c6-a4e1-5c5e9caf0ea1" + ], + [ + "26db5a61-3535-4790-887b-c621297b45ab", + "ec8ab837-8412-45fd-b4e9-992e82135beb" + ], + [ + "26db5a61-3535-4790-887b-c621297b45ab", + "745360a0-be78-488b-bd60-40c2698cbe06" + ], + [ + "0c707775-33af-4885-9d6d-ce23018b7036", + "26db5a61-3535-4790-887b-c621297b45ab" + ] + ], + "roots": [ + "0c707775-33af-4885-9d6d-ce23018b7036" + ] +} \ No newline at end of file diff --git a/fixtures/traces/parent-calls-subagent-twice/otel_tree.txt b/fixtures/traces/parent-calls-subagent-twice/otel_tree.txt new file mode 100644 index 0000000..9eabf96 --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/otel_tree.txt @@ -0,0 +1,12 @@ +Trace: trace-parent-calls-subagent-twice + resource/dims: message_id=msg_042 scenario=parent_calls_subagent_twice session_id=sess_subagent_x2 user_id=dev + +└─ orchestrator#1 (custom) span=0c707775 parent=— + ├─ researcher#1 (custom) span=5feec2ff parent=0c707775 + │ ├─ llm#1 (llm) span=fc9038f7 parent=5feec2ff + │ │ attrs: model_version=stub-researcher + │ └─ web_search#1 (tool) span=694a02ce parent=5feec2ff + └─ researcher#2 (custom) span=26db5a61 parent=0c707775 + ├─ llm#2 (llm) span=ec8ab837 parent=26db5a61 + │ attrs: model_version=stub-researcher + └─ web_search#2 (tool) span=745360a0 parent=26db5a61 diff --git a/fixtures/traces/parent-calls-subagent-twice/otel_waterfall.txt b/fixtures/traces/parent-calls-subagent-twice/otel_waterfall.txt new file mode 100644 index 0000000..e5a792f --- /dev/null +++ b/fixtures/traces/parent-calls-subagent-twice/otel_waterfall.txt @@ -0,0 +1,13 @@ +Trace: trace-parent-calls-subagent-twice + total: 164.5ms [0ms ──► 164.5ms] + resource/dims: message_id=msg_042 scenario=parent_calls_subagent_twice session_id=sess_subagent_x2 user_id=dev + +orchestrator#1 ███████████████████████████████████████████████████████ 164.5ms custom + researcher#1 █████████████████████████ 74.8ms custom + llm#1 ██████████████ 42.3ms llm + web_search#1 ██████████ 31.7ms tool + researcher#2 ████████████████████████ 72.3ms custom + llm#2 █████████████ 40.5ms llm + web_search#2 ██████████ 30.9ms tool + └──────────────────────────────────────────────────────┘ + 0ms 165ms diff --git a/pyproject.toml b/pyproject.toml index e646544..01541bd 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -53,13 +53,18 @@ langgraph = [ "langchain-core>=0.3", "openinference-instrumentation-langchain>=0.1", ] -# OpenTelemetry + Phoenix tracing export (chronicle/instrumentation/openinference.py). -phoenix = [ +# OpenTelemetry + OpenInference (chronicle.instrument_otel, tests). No Phoenix server. +otel = [ "opentelemetry-api>=1.20", "opentelemetry-sdk>=1.20", "opentelemetry-exporter-otlp>=1.20", "openinference-instrumentation>=0.1", "openinference-semantic-conventions>=0.1", +] +# Phoenix UI/collector on top of otel. Kept out of [dev]: recent arize-phoenix +# releases register a pytest plugin that can crash collection (seen on 3.11). +phoenix = [ + "agent-chronicle[otel]", "arize-phoenix>=4", ] # Layer 2 LLM-as-judge (chronicle/judge/runner.py OpenAIJudgeClient). @@ -70,7 +75,7 @@ dev = [ "pytest>=8", "ruff==0.15.22", "build>=1.2", - "agent-chronicle[langgraph,phoenix,judge]", + "agent-chronicle[langgraph,otel,judge]", ] [project.urls] diff --git a/tests/test_execution_graph.py b/tests/test_execution_graph.py index 2cb5b4a..a4a2158 100644 --- a/tests/test_execution_graph.py +++ b/tests/test_execution_graph.py @@ -28,3 +28,37 @@ def test_execution_graph_mermaid(): assert "agent@1" in mermaid assert "delete_file@1" in mermaid assert "-->" in mermaid + + +def test_parent_calls_same_subagent_twice_waterfall(): + """Same sub-agent twice under one parent; each has nested llm + tool spans.""" + graph = ExecutionGraph.load( + Path(__file__).parent.parent + / "fixtures" + / "traces" + / "parent-calls-subagent-twice" + ) + timeline = graph.timeline() + orch = next(e for e in timeline if e.node_id == "orchestrator") + researchers = [e for e in timeline if e.parent_envelope_id == orch.envelope_id] + assert [(e.node_id, e.invocation_index) for e in researchers] == [ + ("researcher", 1), + ("researcher", 2), + ] + for r in researchers: + kids = sorted( + (e for e in timeline if e.parent_envelope_id == r.envelope_id), + key=lambda e: e.sequence, + ) + assert [e.boundary_kind for e in kids] == ["llm", "tool"] + assert [e.node_id for e in kids] == ["llm", "web_search"] + + tree = graph.to_otel_tree() + assert "orchestrator#1" in tree + assert "researcher#1" in tree + assert "researcher#2" in tree + assert "llm#1" in tree and "llm#2" in tree + assert "web_search#1" in tree and "web_search#2" in tree + waterfall = graph.to_otel_waterfall() + assert "█" in waterfall + assert "llm#1" in waterfall and "web_search#2" in waterfall diff --git a/tests/test_nest_attribution.py b/tests/test_nest_attribution.py new file mode 100644 index 0000000..4cfda8d --- /dev/null +++ b/tests/test_nest_attribution.py @@ -0,0 +1,166 @@ +"""OTel-style nest parents + flat dims — boundaries on nodes, not the full agent.""" + +from __future__ import annotations + +from chronicle import ExecutionGraph, boundary, record, wrap_llm +from chronicle.envelope.schema import InputState + + +def test_nested_boundaries_parent_to_active_span(): + """Child spans parent to the open outer boundary, not the last finished one.""" + + @boundary("outer", kind="custom") + def outer() -> str: + return inner() + + @boundary("inner", kind="custom") + def inner() -> str: + return "ok" + + with record("nest-demo", dims={"session_id": "s1", "user_id": "u1"}) as session: + assert outer() == "ok" + + envelopes = session.envelopes + assert len(envelopes) == 2 + by_name = {e.node_id: e for e in envelopes} + assert by_name["inner"].parent_envelope_id == by_name["outer"].envelope_id + assert by_name["outer"].parent_envelope_id is None + assert by_name["inner"].dims["session_id"] == "s1" + assert by_name["outer"].dims["user_id"] == "u1" + + +def test_sibling_roots_when_not_nested(): + @boundary("a", kind="custom") + def a() -> str: + return "a" + + @boundary("b", kind="custom") + def b() -> str: + return "b" + + with record("siblings") as session: + a() + b() + + assert all(e.parent_envelope_id is None for e in session.envelopes) + + +def test_boundaries_on_decision_nodes_not_full_agent(): + """Client pattern: @boundary on llm/tool nodes; orchestration is plain code.""" + + @boundary("planner", kind="llm") + def planner(task: str) -> dict: + return { + "completion": None, + "model": "stub-planner", + "finish_reason": "tool_calls", + "tool_calls": [{"id": "c1", "name": "web_search", "arguments": {"q": task}}], + } + + @boundary("web_search", kind="tool") + def web_search(q: str) -> dict: + return {"results": [f"doc:{q}"], "q": q} + + @boundary("summarizer", kind="llm") + def summarizer(hits: list[str]) -> dict: + return {"completion": f"summary of {hits[0]}", "model": "stub-summarizer"} + + # No @boundary on the full agent — just wire the nodes. + def run_agent(task: str) -> str: + plan = planner(task) + tool = plan["tool_calls"][0] + hits = web_search(**tool["arguments"]) + out = summarizer(hits["results"]) + return out["completion"] + + with record( + "nodes-only", + dims={"session_id": "sess_1", "message_id": "msg_9"}, + ) as session: + assert "summary of doc:vendors" in run_agent("vendors") + + envelopes = session.envelopes + assert [e.node_id for e in envelopes] == ["planner", "web_search", "summarizer"] + assert [e.boundary_kind for e in envelopes] == ["llm", "tool", "llm"] + # Sequential top-level nodes → sibling roots (no fake "agent" parent span). + assert all(e.parent_envelope_id is None for e in envelopes) + assert all(e.dims["session_id"] == "sess_1" for e in envelopes) + + tree = ExecutionGraph.from_envelopes(session.trace_id, envelopes).to_otel_tree() + assert "planner#1" in tree and "web_search#1" in tree and "summarizer#1" in tree + assert "agent#" not in tree + + +def test_graph_node_nests_llm_and_tool_children(): + """LangGraph-style node span: llm + tool called inside parent to that node.""" + + @boundary("llm", kind="llm") + def call_llm(messages): + q = messages[-1]["content"] + return { + "completion": None, + "model": "stub-researcher", + "finish_reason": "tool_calls", + "tool_calls": [{"id": "c1", "name": "web_search", "arguments": {"q": q}}], + } + + @boundary("web_search", kind="tool") + def web_search(q: str) -> dict: + return {"results": [f"doc:{q}"]} + + @boundary("researcher", kind="custom") # graph node, not "the whole agent" + def researcher_node(query: str) -> str: + decision = call_llm([{"role": "user", "content": query}]) + hit = web_search(**decision["tool_calls"][0]["arguments"]) + return hit["results"][0] + + # Plain orchestrator: calls the same node twice — no full-agent boundary. + def run(task: str) -> list[str]: + return [researcher_node("pricing"), researcher_node("risks")] + + with record("graph-node-nest", dims={"session_id": "s2"}) as session: + assert run("compare") == ["doc:pricing", "doc:risks"] + + researchers = [e for e in session.envelopes if e.node_id == "researcher"] + assert len(researchers) == 2 + assert all(r.parent_envelope_id is None for r in researchers) + + for r in researchers: + kids = sorted( + (e for e in session.envelopes if e.parent_envelope_id == r.envelope_id), + key=lambda e: e.sequence, + ) + assert [e.node_id for e in kids] == ["llm", "web_search"] + assert [e.boundary_kind for e in kids] == ["llm", "tool"] + assert kids[0].parent_envelope_id == r.envelope_id + assert kids[1].parent_envelope_id == r.envelope_id + + waterfall = ExecutionGraph.from_envelopes( + session.trace_id, session.envelopes + ).to_otel_waterfall() + assert "researcher#1" in waterfall and "researcher#2" in waterfall + assert "llm#1" in waterfall and "web_search#2" in waterfall + + +def test_wrap_llm_nests_under_graph_node(): + def dispatch(messages, **kwargs): + return {"content": "hi", "model": "stub-model"} + + llm = wrap_llm( + "llm", + dispatch, + extract_input=lambda messages, **kw: InputState(messages=list(messages)), + extract_result=lambda r: r, + ) + + @boundary("researcher", kind="custom") + def researcher_node() -> str: + return llm([{"role": "user", "content": "hi"}])["content"] + + with record("wrap-nest", dims={"message_id": "m9"}) as session: + assert researcher_node() == "hi" + + by_name = {e.node_id: e for e in session.envelopes} + assert by_name["llm"].parent_envelope_id == by_name["researcher"].envelope_id + assert by_name["llm"].dims.get("model_version") == "stub-model" + assert by_name["llm"].dims["message_id"] == "m9" diff --git a/tests/test_otel.py b/tests/test_otel.py index 132566b..f28c9e7 100644 --- a/tests/test_otel.py +++ b/tests/test_otel.py @@ -48,6 +48,21 @@ def finalize(state, tool_result): return finalize(state, tool_result) +def _run_nested_agent(): + """True call-stack nesting: tool runs inside the outer agent boundary.""" + + @boundary("refund", kind="tool") + def refund(order_id, amount_cents): + return {"status": "blocked", "blocked": True, "amount_cents": amount_cents} + + @boundary("agent", kind="llm") + def agent(state): + tool_result = refund("o1", 999) + return {**state, "completion": "done", "blocked": tool_result["blocked"]} + + return agent({"messages": []}) + + def test_one_span_per_crossing_with_openinference_attrs(): tracer, exporter = _tracer_and_exporter() with chronicle.record("t-otel"): @@ -68,13 +83,25 @@ def test_one_span_per_crossing_with_openinference_attrs(): def test_spans_nest_by_parent_linkage(): tracer, exporter = _tracer_and_exporter() with chronicle.record("t-nest"): + chronicle.instrument_otel(tracer=tracer) + _run_nested_agent() + + finished = exporter.get_finished_spans() + # Child (refund) finishes before parent (agent) — export order is end order. + by_name = {s.name: s for s in finished} + assert by_name["agent"].parent is None + assert by_name["refund"].parent is not None + assert by_name["refund"].parent.span_id == by_name["agent"].context.span_id + + +def test_sequential_top_level_spans_are_siblings(): + tracer, exporter = _tracer_and_exporter() + with chronicle.record("t-sib"): chronicle.instrument_otel(tracer=tracer) _run_agent() - agent1, refund, agent2 = exporter.get_finished_spans() - assert agent1.parent is None - assert refund.parent.span_id == agent1.context.span_id - assert agent2.parent.span_id == refund.context.span_id + spans = exporter.get_finished_spans() + assert all(s.parent is None for s in spans) def test_error_boundary_sets_error_status():