Stamp a node's spend on its error event, so an overspent run can say so (#84)

Tokens were attributed from `end` events only. A node the budget interrupts
emits `error` instead, so the spend that triggered enforcement vanished from
the run's own account of itself: `grapharc metrics` said `tokens: 0` for a run
stopped with `max_tokens reached (51/5)`.

Every `error` event now carries what its node spent, exactly as `end` does,
and both `summarize` and the cost report count it. Sub-events inside a node
stay a breakdown of its total rather than an addition, so the disjointness
that kept `ends + orphans` from double-counting holds unchanged, and the
`RunCost.tokens == RunMetrics.tokens` invariant the suite asserts still does.

The basics cookbook stated what each phase carries and had to be re-recorded,
which is the page doing its job.

Co-authored-by: Claude Fable 5 <noreply@anthropic.com>

Author: Shashankss1205

CHANGELOG.md

@@ -7,6 +7,10 @@ and "used to be true" — the two things a reader most needs kept apart.
 
 Entries are newest-last within a release, matching the order they were written.
 
+## Unreleased
+
+- a run **stopped for overspending reported spending nothing**. Tokens were attributed from `end` events, and a node the budget interrupts emits `error` instead — so `grapharc metrics` answered `tokens: 0` for a run whose own enforcement message named the figure that stopped it (`max_tokens reached (51/5)`). The audit trail lost precisely the number the stop was about, and per-node attribution dropped the most expensive node in the run. Every `error` event is now stamped with what its node spent, exactly as `end` is, and both `summarize` and the cost report count it; sub-events inside a node remain a breakdown of its total rather than an addition, so the disjointness that kept `ends + orphans` from double-counting is unchanged, and `RunCost.tokens == RunMetrics.tokens` still holds.
+
 ## 0.1.3
 
 - `grapharc plan` drives the governed loop; `PolicyEngine.edge_policy()` compiles the TOML document into the gate `AdmissionChecker` consults, and `grapharc plan --policy` is the caller; `grapharc demo --memory PATH` hands the shipped graphs the durable SQLite store.

docs/cookbook/01-basics.md

@@ -803,7 +803,7 @@ Output:
 {'attempt': 1, 'graph': 'counter', 'node': 'load', 'phase': 'start', 'step': 1}
 {'attempt': 1, 'graph': 'counter', 'node': 'load', 'phase': 'end', 'step': 1, 'state_delta': {'items': ['a', 'b', 'c']}, 'tokens': 0}
 {'attempt': 1, 'graph': 'counter', 'node': 'count', 'phase': 'start', 'step': 2}
-{'attempt': 1, 'graph': 'counter', 'node': 'count', 'phase': 'error', 'step': 2, 'error': "ValueError('the counter is not implemented yet')"}
+{'attempt': 1, 'graph': 'counter', 'node': 'count', 'phase': 'error', 'step': 2, 'tokens': 0, 'error': "ValueError('the counter is not implemented yet')"}
 ```
 
 The four fields the snippet filtered out are on every line too: `ts` (ISO-8601 UTC),
@@ -823,8 +823,12 @@ So, by phase:
   node never returns.
 - **`end`** adds `state_delta` (exactly the validated update that was applied),
   `duration_ms`, and `tokens` charged during that node.
-- **`error`** adds `duration_ms` and `error` — `repr()` of the exception, so the type
-  is preserved. There is no `state_delta`, because a node that raised wrote nothing.
+- **`error`** adds `duration_ms`, `error` — `repr()` of the exception, so the type is
+  preserved — and `tokens`, the spend charged during that node before it failed.
+  There is no `state_delta`, because a node that raised wrote nothing. The token
+  count is there for the same reason `end` carries one: a run stopped *for*
+  overspending used to report having spent nothing, because the only number the
+  audit trail read was on the event an interrupted node never writes.
 
 **Why it works this way.** `start` and `end` share a step number; the pair is the
 node execution. That means step numbers do not order the file — read events in file

grapharc/observe/metrics.py

@@ -53,7 +53,14 @@ def summarize(recorder: TraceRecorder, run_id: str) -> RunMetrics | None:
     # Work the reconstruction could not place inside any node. Disjoint from
     # `ends` by construction, so adding it cannot double-count a node total.
     orphans = replay(recorder, run_id).orphan_sub_events
-    measured = [*ends, *orphans]
+    # `errors` are measured too, and for the same reason `ends` are: the kernel
+    # stamps a node's terminal event with what that node spent, whichever way it
+    # ended. Counting only `end` meant a run *stopped for overspending* reported
+    # `tokens: 0` — the audit trail losing precisely the spend that triggered
+    # enforcement. Sub-events inside a node are a breakdown of its total rather
+    # than an addition to it, so the disjointness that makes `ends + orphans`
+    # safe holds here unchanged.
+    measured = [*ends, *errors, *orphans]
     reason = None
     # Scanned across every event, not just `end`: an agent writes its
     # `termination_reason` on a `stop` event, and that is still why it stopped.

grapharc/observe/replay.py

@@ -136,8 +136,12 @@ def tokens(self) -> int:
         token it spent in `orphan_sub_events`, and reporting zero for it was
         the audit trail contradicting itself. The two sets are disjoint, so
         nothing is counted twice.
+
+        A node that *failed* counts too. Its terminal `error` event carries what
+        it spent, exactly as an `end` does, so excluding it here reported zero
+        tokens for a run the budget stopped for spending too many.
         """
-        return sum(e.tokens for e in self.executions if e.ok) + sum(
+        return sum(e.tokens for e in self.executions) + sum(
             e.tokens or 0 for e in self.orphan_sub_events
         )
 

grapharc/runtime/graph.py

@@ -710,15 +710,29 @@ def _leave(
             try:
                 result, delta = self._check_result(f"node {name!r}", writes, result)
             except (WritePermissionError, StateTypeError, GraphRoutingError) as err:
-                emit("error", duration_ms=duration_ms, error=str(err))
+                emit(
+                    "error",
+                    duration_ms=duration_ms,
+                    error=str(err),
+                    tokens=ctx.meter.tokens - tokens_before,
+                )
                 raise
 
         # Tokens are charged mid-node by the usage callback, so this is the
         # first boundary at which a spend made inside the node can stop the run.
         try:
             ctx.meter.check_tokens()
         except BudgetExceeded as exc:
-            emit("error", duration_ms=duration_ms, error=f"budget: {exc.reason}")
+            # Stamped with what the node spent, exactly as `end` is. Without it
+            # the run stopped *for overspending* and then reported spending
+            # nothing, which is the audit trail losing the one number the stop
+            # was about.
+            emit(
+                "error",
+                duration_ms=duration_ms,
+                error=f"budget: {exc.reason}",
+                tokens=ctx.meter.tokens - tokens_before,
+            )
             raise
 
         # The provider's own price for every model call made inside this node,
@@ -765,8 +779,14 @@ async def awrapped(state: Any, config: RunnableConfig) -> Any:
                 except BaseException as exc:
                     # BaseException, not Exception: an async node is stopped by
                     # cancellation, which is not an Exception, and a stop with no
-                    # trace line is a stop nobody can audit afterwards.
-                    emit("error", duration_ms=(time.perf_counter() - t0) * 1000, error=repr(exc))
+                    # trace line is a stop nobody can audit afterwards. Carries
+                    # the node's spend for the same reason `end` does.
+                    emit(
+                        "error",
+                        duration_ms=(time.perf_counter() - t0) * 1000,
+                        error=repr(exc),
+                        tokens=ctx.meter.tokens - tokens_before,
+                    )
                     raise
                 return self._leave(
                     name,
@@ -800,7 +820,12 @@ def wrapped(state: Any, config: RunnableConfig) -> Any:
                 # ^C, which is a KeyboardInterrupt and not an Exception, and a
                 # stop with no trace line is a stop nobody can audit afterwards.
                 # The exception is re-raised untouched; only the record is new.
-                emit("error", duration_ms=(time.perf_counter() - t0) * 1000, error=repr(exc))
+                emit(
+                    "error",
+                    duration_ms=(time.perf_counter() - t0) * 1000,
+                    error=repr(exc),
+                    tokens=ctx.meter.tokens - tokens_before,
+                )
                 raise
             return self._leave(
                 name,

tests/test_budget_enforcement.py

@@ -665,3 +665,43 @@ def slow(state):
 def test_a_deadline_exceeded_is_a_budget_exceeded():
     """Callers that already catch BudgetExceeded must keep catching timeouts."""
     assert issubclass(NodeDeadlineExceeded, BudgetExceeded)
+
+
+def test_a_run_stopped_for_overspending_reports_what_it_spent(tmp_path):
+    """The audit trail must not lose the spend the stop was about.
+
+    Tokens were attributed on `end` events only, and an interrupted node emits
+    `error` instead — so a run killed *for* exceeding `max_tokens` reported
+    `tokens: 0`, contradicting the enforcement message that named the figure.
+    """
+    import json
+
+    from grapharc.observe.metrics import summarize
+    from grapharc.observe.replay import replay
+    from grapharc.observe.trace import TraceRecorder
+
+    class State(GraphARCState):
+        out: str = ""
+
+    def spend(state: State) -> dict:
+        model = ScriptedChatModel(responses=["x" * 200], on_exhausted="repeat")
+        return {"out": str(model.invoke("hi").content)[:10]}
+
+    trace = TraceRecorder(tmp_path / "t.jsonl")
+    g = GraphARC(State, name="overspend", trace=trace, budget=Budget(max_tokens=5))
+    g.add_node("spend", spend, writes={"out"})
+    g.add_edge(START, "spend")
+    g.add_edge("spend", END)
+
+    with pytest.raises(BudgetExceeded) as caught:
+        g.compile().invoke({})
+
+    spent = int(str(caught.value).split("(")[1].split("/")[0])
+    assert spent > 0, "the meter charged something, or this test proves nothing"
+
+    run_id = json.loads((tmp_path / "t.jsonl").read_text().splitlines()[0])["run_id"]
+    metrics = summarize(trace, run_id)
+    assert metrics.tokens == spent, "the audit trail must agree with the enforcement"
+    assert metrics.errors == 1
+    # The cost report and the audit trail must never disagree.
+    assert replay(trace, run_id).tokens == metrics.tokens

tests/test_cookbook_basics.py

@@ -565,6 +565,7 @@ def count(state: State) -> dict:
             "node": "count",
             "phase": "error",
             "step": 2,
+            "tokens": 0,
             "error": "ValueError('the counter is not implemented yet')",
         },
     ]