1.10.0 — the trace records the token budget and what each attempt spent

run_end records the token budget that was in force and what each attempt actually spent, so a
TRUNCATED completion stops being indistinguishable from a MALFORMED one.

Added

• run_end.payload.budgets — the generation cap that was APPLIED, per role. A consumer's run
  died with AdapterParseError: LM response cannot be serialized to a JSON object on a response that
  opened with the model's own reasoning prose inside the JSON envelope, and it read as a small model
  failing to follow the format. It was a max_tokens truncation. dspy detects that — _check_truncation
  tests finish_reason == "length" — and then only logger.warnings it, discarding the datum before
  any caller can see it; the only evidence was a container log line that rotates. The exception TYPE
  is identical either way, so this is the misdiagnosis 1.4.0 already documented under max_tokens,
  recurring because nothing recorded the one fact that separates them.

  Recorded alongside the token cap: the ITERATION caps (max_iterations, max_llm_calls,
  max_output_chars) and a dropped flag saying whether _build_rlm's except TypeError fired —
  that path reverts all three to dspy's own defaults, so without the flag the configured numbers
  would read as applied when they were not. max_output_chars matters to the diagnosis in its own
  right: dspy head+tail-caps each REPL output, so "the output was cut off" has THREE independent
  mechanisms and a reader has to be able to rule each out.

  Read off the LM, never from RLMConfig: an injected main_lm/sub_lm is used verbatim, so the
  configured cap can be one the call never used — which is exactly the consumer whose run died. The
  recorded key says which name held it, because dspy rewrites max_tokens to
  max_completion_tokens for OpenAI reasoning models and a reader of the first name alone gets
  None for precisely the thinking-model case this exists to explain. Named keys only — a
  trace is a shipped artifact and lm.kwargs carries api_key for every LM the kit builds.

• run_end.payload.usage — token counts, per ATTEMPT. completion_tokens == cap is a
  truncation, and unlike a boolean the ratio also shows a turn APPROACHING the cap, which is the
  early warning nobody has ever been able to see. Collected through dspy's public usage API, whose
  tracker the kit HOLDS — so the counts survive the exception, and the fatal call's tokens are
  recorded for a run that raised. That is the whole point: the run being diagnosed is one that died.

  Per attempt, with turns_recorded marking the attempt whose turns are in the trace, because
  run_with_retry re-runs the whole trajectory and the attempt that reached the trace is NOT always
  the last — a run whose FINAL attempt raises keeps an EARLIER attempt's turns. Scoping usage to
  "the attempt with the turns" would have discarded the fatal call's tokens. A run that never
  produced a prediction (main_steps: 0, the shape of the incident behind this) records every
  attempt with none flagged.

  Not per TURN, and that is a limit rather than an omission: sub_model falls back to
  main_model and dspy propagates the tracker into its sub-LM workers, so planner turns, sub-LM
  escalations and same-model tool-LM calls land in one flat list under one key with no call id and
  no timestamp. Nothing in dspy's tracker can separate them. For a distribution over runs use
  max(completion_tokens), never the run's SUM — summing many turns against a per-completion cap
  answers a cost question, not this one.

• A caller's own dspy.track_usage() is REUSED, not shadowed. dspy installs a tracker only when
  none is set, so installing unconditionally would hand a consumer measuring cost around
  task.arun(...) ZERO entries for everything inside — this kit writing a structural zero into
  someone else's measurement. The kit reuses an installed tracker and reads a per-attempt SLICE, so
  the consumer's own calls are never counted as the run's. One disclosed cost when the kit installs
  one because you had none: dspy attaches per-prediction usage only when no tracker is installed, so
  a dspy.Module a consumer calls from inside a kit run gets None from get_lm_usage(). The
  counts are still in the tracker and in the trace; that one accessor stops answering.

Not done, deliberately

• An in-loop recovery for a truncated or unparseable turn was requested and is refused. dspy DOES
  expose the seam — Adapter.__call__/acall, where JSONAdapter already re-calls on a parse
  failure, and which this kit already subclasses and deliberately strips of that fallback. But a
  recovery there is invisible to the trajectory: the RLM loop never sees it, so the corrective
  exchange is not a main_step — a second unrecorded turn added to a failure whose defining problem
  is that the deciding turn is unrecorded. It also doubles the cost of the runaway actually observed.
  The version worth having needs the loop, so it belongs upstream: extending dspy's existing
  CodeExecutionError feedback path to a parse failure would make it a real turn with a real number.

• RUN_FACT_KEYS is unchanged. The trace payload gains the fields; compute_run_facts does not.
  With per-turn attribution impossible, a truncated_turns count would be per-run and weaker than
  its name implies.

1.9.1 — tool_total_seconds measures occupied wall-clock, not a sum

tool_total_seconds measures the wall-clock tool calls OCCUPIED, instead of adding their durations
together and counting a nested call twice.

Fixed

• compute_run_facts's tool_total_seconds / tool_wasted_seconds are the measure of the UNION
  of the tool calls' intervals, not a cross-tool sum. A tool that records another tool_call from
  inside itself produces two CORRECT events describing one stretch of wall clock; adding them
  reports time that was never spent. On a real trace the sum reached 136.5% of the run's own
  span — impossible for a wall-clock share, and produced by this kit's own code. Five traces from
  one consumer moved 42.8→23.3%, 83.1→46.0% and 136.5→69.4%. The two with nothing nested moved by
  reconstruction error alone, which has TWO terms and not one: +1.6e-7 s on the first (float
  quantisation) and −7.8 ms on the second, where a 0.9 s call and a 298 s call reconstructed as
  overlapping by that much of clock drift though they ran back to back. As a share of each metric's
  own previous value that is +0.00000% and −0.00208%; as a share of the run's span, +0.0000000% and
  −0.00094%. Seconds are quoted first here because the two ratios have different denominators and
  the drift term, unlike the float one, grows with the length of the call.

  It takes BOTH halves to happen, which is why it went unseen: the key has been a sum since 1.8.0,
  but the double-count needs 1.8.3's auto-timing of the OUTER tool AND an inner call recorded
  explicitly by the tool itself — so it could only ship in 1.8.3, 1.8.4 and 1.9.0. A consumer
  whose tool graph is flat never saw it, and the number stays under 100% — 42.8%, 83.1% — until the
  nested call dominates the run, so nobody catches it by inspection.

  Each event contributes [ts - duration_s, ts]. That is sound across the two clocks involved
  (ts is time.time, duration_s a time.perf_counter delta) because a delta is clock-agnostic
  and fixes the interval's LENGTH — but nothing fixes its POSITION. The clocks differ in RATE, so a
  reconstructed start is displaced by roughly duration_s x drift, and the error grows with the
  call: two observations in one corpus put it at >= 26.3 and >= 29.9 ppm, i.e. 7.8 ms and 17.3 ms on
  calls of 298 s and 577 s. Every such observation is a lower bound, so the union can invent a small
  overlap between strictly sequential calls or erase a real one. It moves the fifth decimal place
  against a nesting effect measured in hundreds of seconds. record_tool_call's docstring now
  states the precondition this rests on: the envelope ts must be the END of the measured window.

• compute_run_utilization no longer raises on a tool_call whose payload is None.
  dict.get's default fires only on a MISSING key, never on a key present with a None value, so
  event.get("payload", {}).get("tool", ...) raised AttributeError. compute_tool_waste already
  handled it with or {}; the two now agree, and such an event counts as tool "?" with cause
  invalid. A public name in __all__, so the behaviour change is noted here rather than only in
  the code.

Changed

• tool_total_seconds no longer equals sum(w.total_seconds for w in compute_tool_waste(...)).
  It is strictly SMALLER once any call nests, and otherwise equal only up to reconstruction error —
  where it can be a few 1e-7 s LARGER, because ts - (ts - d) is quantised at epoch scale. Do not
  write assert new <= old: on a flat run with 24 calls and nothing nested it already fails, by
  +1.6e-7 s. This is the one behavioural break: a consumer
  re-deriving the total from the per-tool dict will see a difference on any run with a nested call.
  ToolWaste's own per-tool numbers are deliberately unchanged and stay SUMS — "what this tool's
  calls cost, added up" is well defined under overlap; it is the cross-tool aggregate that must not
  double-count.
• A consumer tracking tool_total_seconds across the upgrade sees a step, downward on any run
  with a real nest. tool_wasted_seconds changes with it, and its derived SHARE can move UP — an
  ok call nested inside an invalid one reads 0.556 before and 1.000 after. Not observed on the
  corpus behind this release, where every wasted call was flat, but latent for anyone whose failures
  wrap other calls.
• The changed value is also written INTO traces by TraceRecorder(record_metrics=True), which
  folds these facts into the run_end payload. Nothing is added, removed or re-typed, so trace/v1's
  additive-only rule is intact — but a corpus spanning the upgrade holds two meanings of
  payload.metrics.tool_total_seconds in-file, distinguishable only by run date.
• compute_run_facts on a MULTI-RUN list changes its conflation direction. It already warns
  that a multi-run list silently conflates; today that over-adds, and the union can now silently
  UNDER-add by merging two concurrently-executed runs' intervals. Use compute_run_facts_by_run.

Removed

• _sum_or_none (private, unused once both keys move). Its None-vs-0.0 discipline moves into
  the new helper: None when nothing carried a duration, decided over ALL tool calls and never over
  the wasted subset — gating on the subset reports None where a healthy run should report 0.0.

v1.9.0

verify_quote now reads a line-numbered citation as a coordinate claim and verifies it, instead of
searching the gutter's digits as if they were content.

Added

• A guttered quote is resolved by coordinate. 1.8.2 closed the case where a citation of NOTHING
  verified and documented what it left open: a guttered quote carrying CONTENT was searched with the
  gutter DIGITS as literal text, so it matched wherever that number happened to precede the line's
  text — across a mandatory whitespace junction, and therefore across blank lines.

  Rendering every non-blank line of every .py in this repo and verifying it against its own file
  found 2 such matches in 18,761, and both are HONEST citations whose content really is at the
  gutter's line. One is a full line of code. The function was reporting a coordinate the citation
  never claimed; both now resolve correctly.

  A guttered quote verifies when four things hold: its gutters are consecutive, the line numbers are
  in range, the content sits at exactly the line the gutter names, and that block occurs exactly
  once in the source as a contiguous line sequence. Otherwise nothing changes and the ordinary
  search runs.

  The gutter is used, never stripped. Stripping it and searching the remainder — the repair this
  function refused for four releases — accepts a citation naming the WRONG line whenever the
  remainder appears anywhere else. Both halves of the replacement are load-bearing: without
  uniqueness a bare position check is WORSE than searching, because 16.84% of non-blank lines here
  recur in their own file, so a fabricated coordinate verifies at roughly 0.15% against 0.000% for a
  plain search. Without exactness a fabricated INDENTATION level verifies, since 2.16% of lines here
  are exact-unique but identical after stripping, and in Python indentation is semantics. With both,
  fabrication is closed by construction: exact content at line n plus a block occurring once means
  n is the only line that can hold it.

  Uniqueness is a contiguous LINE SEQUENCE, not a substring count — the second residual's content is
  ), which has hundreds of substring hits and one whole-line hit, so a substring criterion would
  have missed it entirely.

Changed

• A coordinate-verified MATCH means something different, and says so. The source holds the
  CONTENT at that line, but the quoted bytes — gutter included — are not a substring of it. A caller
  re-deriving grounding host-side with quote in source must branch on the text; the MATCH:
  prefix is unchanged for callers that branch on that.

• normalize_whitespace=False skips the coordinate path. Byte-exact mode means no
  interpretation, and reading a gutter as a coordinate is an interpretation. It is also the lever
  when source is itself a numbered listing, where a correct literal match would otherwise be
  overridden — a shape found in none of the
  tens of thousands of local text files scanned, though cat -n and nl emit it.

• Two pinned test verdicts move, and that is the feature. A quote of " 1\tx = 42" against
  a source whose line 1 is x = 42 was a MISMATCH; it is now a coordinate-verified MATCH.

Not a fix — a constraint on the new code

• The gutter is bounded to nine digits, and that is why nothing raises. verify_quote documents
  that it never raises, and on CPython 3.11 int("9" * 4301) raises ValueError: Exceeds the limit (4300) for integer string conversion. No released version ever converted a digit run, so this
  fixes no regression; an unbounded [0-9]+ in the NEW recognizer would have introduced one. Nine
  digits covers 999,999,999 lines.

• The closest-line hint on a failed coordinate check was considered and left alone. A guttered
  quote that falls through is diffed against source lines with its gutter attached, which depresses
  the similarity ratio for exactly this class. Hinting with the parsed content instead is a change
  to the MISMATCH path with its own verdict surface, and it is not this release.

What this does NOT close

16.84% of non-blank lines recur in their own file, and a citation of one of those stays
uncoordinated — 32.8% of everything read_file renders, once blank-line citations refused by the
1.8.2 guard are counted. Those keep exactly today's verdict, and that class contains no wrong-line
matches to inherit: every one of the 18,759 non-residual honest quotes was already a MISMATCH.

v1.8.4

A failed run's trace now says why it failed — and, separately, stops losing the event that says so.

Fixed

• A lone surrogate anywhere in a payload lost the event. record() json-dumps with
  ensure_ascii=False into a handle that had STRICT error handling, so a single unencodable
  character raised UnicodeEncodeError out of record() and nothing was written. Reproducible on
  shipped code with nothing exotic:

  rec.record("main_step", {"code": "x = '/data/caf\udce9'"})   -> UnicodeEncodeError
  

  os.fsdecode, a surrogateescape decode, and a model completion embedded in a dspy adapter
  error all produce them. The handle now opens with errors="backslashreplace", which round-trips
  byte-exactly through load_events — backslashreplace writes the escape, JSON reads it back — and
  leaves ordinary text alone, because the handler fires only on characters that cannot be encoded
  at all. run_end's error survived this until now only because repr() happens to escape
  surrogates.

Added

• run_end.payload["error_chain"] — the causes below the outer exception. run_with_retry
  raises RLMTaskError(...) from the last real failure, so the cause is chained on the object,
  and the repr() that was all run_end recorded drops it. RLMTaskError's message is
  deliberately generic, so a failed run's trace said only that it had failed.

  Across the nine-consumer fleet that was 15 of 15 recorded failures with no recoverable cause —
  on the one artifact that outlives an intermittent failure. What prompted it: two live runs failed
  identically and the same case then succeeded unchanged, so there was nothing to reproduce and
  nothing recorded to read.

  Each frame is short_error(e) — Type: message, head and tail kept, bounded near 600 characters
  (its contract is "never longer than the limit plus an elision marker" — a frame measures 624-630 on
  messages up to 10 MB, the figure moving with the digit count in that marker, so treat it as a
  bound rather than a number) — reusing the
  public helper run_with_retry already logs each attempt with, rather than promoting repr() —
  which renders an EXCEPTION at exactly one place in the package, the error line just above. The outer frame is
  not repeated, since error already holds it.

  Written only when a chain exists, so a reader can tell "no cause" from "could not build one".
  Never a traceback: a traceback names every frame's file and line, while a message carries only
  what the raiser put in it — a difference of degree, since a message can itself hold a path. Capped at five
  frames, truncating the OUTER end so the root cause survives a deep chain. The walk follows
  __cause__, else __context__ unless __suppress_context__. What sets __context__ is a NEW
  exception raised while another is in flight without from — most often inside an except, but a
  finally or a function called from one does it too. The kit has zero of those (AST-verified) and
  so only ever chains via __cause__; dspy, litellm and httpx raise that way.

  Unconditional, not opt-in, and the RLM_TRACE_METRICS precedent does not apply. That one
  defaults off because its facts are DERIVABLE — compute_run_facts(events) is the authority and
  the snapshot is convenience. A cause chain exists only on the live exception and is gone the
  moment __exit__ returns. Gating it would also repeat what 1.7.0 and 1.8.3 each shipped a fix
  for: a field that depends on someone opting in is missing for someone.

  Two cautions before forwarding a frame anywhere. Unlike error's repr, a frame is not
  guaranteed single-line — pydantic and dspy adapter errors are multi-line. And an exception
  message can carry a URL with a query-string token; this kit has no scrubber, and short_error's
  cap is the whole mitigation. The exposure already existed for error; the chain widens it to
  third-party frames, which is where such a token most often lives.

v1.8.3

Every tool a task hands the model now records how long it took, without its author doing anything.
Two documented rules are reversed to make that true, and both reversals have the same cause.

Fixed

• duration_s existed only where its author remembered, which is the sub_call failure one
  field over. Six of the kit's tool sources measured themselves; the filesystem and knowledge tools —
  27 record_tool_call sites across fs.py, edit.py, archive.py and skills.py — did not. So
  metrics.compute_tool_waste's *_seconds read None for them everywhere, and ToolWaste is
  explicit that None means "nothing measured" rather than zero.

  A consumer could not fix it either. One whose read_file / grep_repo / read_skill are
  pure delegation to these factories has no seam of its own; wrapping the callable to add a
  duration would emit a SECOND tool_call and double tool_calls, tool_ok and everything
  derived from them. It was right to refuse, and the only place to fix it was here.

  RLMTask._build_rlm now wraps every tool it hands the model — the same seam and the same reason
  as 1.7.0's automatic sub_call wrapper. The wrapper publishes a start time and records nothing
  itself, so it cannot double-count; record_tool_call fills duration_s from it only when the
  caller passed none. A tool that measures itself keeps its own figure, because it scopes the window
  more tightly — fetch_url starts its clock after the SSRF check, run_command keeps a
  runner-reported number alongside. A consumer's own tools are covered with no work.

  What it deliberately does not reach, each failing back to an absent field rather than a wrong
  one. A dspy.Tool OBJECT is passed through untouched — mcp._make_tool returns one, and it is a
  pydantic model with no __name__, so wrapping it would leave the wrapper called timed: two MCP
  tools would abort the task with "Duplicate tool name", one would register as timed with its
  args collapsed to {"kwargs": {}}. MCP records its own duration anyway. A coroutine function is
  passed through too, because dspy branches on inspect.iscoroutinefunction, which does not follow
  __wrapped__ — deleting that one line turns a run that completes into RLMTaskError: You are calling __call__ on an async tool. So are a callable class instance and a functools.partial,
  neither of which functools.wraps can wrap without changing what dspy registers. And a GENERATOR FUNCTION -- one whose body
  contains a yield -- is wrapped like any other yet records nothing: calling it only builds the
  generator object, and the wrapper releases the start time before the body, and the
  record_tool_call inside it, ever runs. (A plain function that merely RETURNS a generator
  expression is a different shape and is timed normally; the distinguishing word is function,
  not returns.)

  Note the dspy.Tool passthrough is safe for MCP because MCP records its own duration; a
  dspy.Tool a CONSUMER builds does not, and must pass duration_s itself.

  The fill is matched on the tool's name, and that is load-bearing. Only what the task hands
  the model is wrapped, so a COMPOSITE tool — a consumer's tool calling a kit tool inside itself —
  would otherwise charge its whole window to every event recorded beneath it. Measured before the
  check existed: two zero-cost read_file calls inside a 0.25 s tool each reported 0.25 s, which
  triples compute_tool_waste.total_seconds. That is worse than the None it replaces — None is
  an honest unknown, that was a confident wrong answer — so a mismatch fills nothing.

  Applied at the task seam rather than inside each factory, which is safe for the annotations
  DESPITE the distance rather than because of it: every tools/*.py uses
  from __future__ import annotations, so the annotations functools.wraps copies are strings
  that only resolve in the defining module — and they survive only because typing.get_type_hints
  walks __wrapped__ to find those globals. A factory-local wrapper would have resolved them
  trivially; this one depends on a CPython behaviour, which is why it is tested rather than assumed.
  Verified against dspy 3.3.1 on the 3.11 floor, where a Tool construction failure would abort
  registration for every tool on the task, not just the wrapped one.

Changed

• A refused call now carries a duration. It used to record none, on the argument that a blocked
  URL never touched the network so a ~0 would be noise. None means "nobody measured", so spending
  it on "measured, and it was instant" makes the two indistinguishable — the mistake 1.7.0 shipped
  a release to correct. The reversal is stated in the guide, in make_fetch_tool and
  make_web_search_tool, and in the test that used to pin the old rule.

• grep_files is no longer exempt from timing, reopened by its own terms. Its exemption rested
  on a measurement — n=146, median 0.029s, max 0.746s — and named "a pathological regex over a
  large tree" as what would reopen it. Re-measured on a consumer deployment across nine real
  repositories, 7 patterns x 3 runs each: median 744 ms, p95 4.8 s, max 6.3 s on a 2,110-file
  repository. It does not scale with file count — a 102-file repo measured slower than a
  1,210-file one — so the driver is bytes and match count. Against that corpus the tool alone is
  about 40% of all sandbox execution time. The old number was not wrong; it was taken on a corpus
  with no large repository in it.

• Do not average a compute_tool_waste figure across this upgrade. A tool that reported None
  before reports a real number after, so a corpus spanning the boundary mixes "unmeasured" with
  "measured" in the same denominator — the same warning the 1.7.0 sub_call note carries, and
  run_start.rlm_harness is what separates the cohorts.

v1.8.2

One correctness fix in shipped code. It is model-visible: dspy builds a tool's description from
func.__doc__, and verify_quote is registered directly as a REPL tool, so its refusal text and
its docstring reach every consumer's model on every call.

Fixed

• A quote carrying only a line number verified against almost anything.
  make_read_file_tool(line_numbers=True) renders a line as f"{n:>6}\t{line}", so a BLANK line
  renders as " 7\t" — and " 7\t".strip() is "7". Non-empty, so it passed the
  empty-quote guard, and the search then reduced to the bare pattern 7, matching any source
  containing that digit:

  verify_quote("x = 42\n\ny = 1\n", "     2\t")
  -> MATCH: found at line 1 (char 5)
  

  A citation of nothing verified, at a line the citation never claimed. The guard's own stated
  reason for existing — "trivially matches almost any real text, a meaningless confirmation, not a
  real check" — describes that case exactly and did not fire on it.

  The guard now covers a second shape: a quote whose every non-blank line is a bare number, refused
  before any search, with its own message rather than the empty-quote one. The rule reads the whole
  line loosely on purpose, because the render is not what arrives — a model trims the trailing tab
  (" 2"), writes a space for it (" 2 "), or keeps the newline the renderer emits
  (" 2\t\n"), and a tighter pattern catches none of those. It matches ASCII digits only;
  \d accepts fullwidth and Arabic-Indic numerals, which are content here, not coordinates.

  It encodes no line-number format, so grounding.py stays independent of the tools that render
  one. edit_file's success snippet uses the same convention and was never documented as a source
  of guttered text; it is now.

  This closes the fully-blank case, not the whole class. A guttered quote that carries content
  is not refused, and the gutter NUMBER is then searched as literal content — so the quote matches
  wherever that number happens to precede the line's text, including across a mandatory \s+ that
  spans blank lines. A full line of code is reachable that way, not only a line of punctuation.
  From this repo's own suite: a quote claiming line 42 of tests/test_async.py verifies at line
  39, because line 39 ends == 42 and the pattern becomes 42\s+def\s+test_run_.... Measured by
  rendering every non-blank line of every .py here and verifying it against its own file, that is
  2 false matches in 17,412 quotes, about 1 in 8,700.

  Closing them needs the gutter-stripping repair, which is deferred: a position-checked design was
  built and audited, and it splits lines differently from the renderer in a way that verifies
  FABRICATED citations on any file containing a form feed. That needs its own release.

  What this costs. An all-digit quote no longer verifies even when the digits are genuinely in
  the source — verify_quote("port = 8080", "8080") is refused, and so is a multi-line quote whose
  every line is a number, such as a column lifted from a numeric file. For a short number that is
  the point, since the match was never evidence of anything. For a long one it is a real loss: an
  18-digit identifier appearing verbatim IS strong evidence, and it is refused too. The rule is
  blunt on purpose — it cannot tell a coordinate from a datum, and the failure it prevents is worse
  than the one it causes. It was 0 of 1,363 citations in a consumer corpus.

Docs

• Line numbers and verify_quote are complementary, not alternatives — a consumer read them as
  a choice, turned numbers off to keep verification passing, and paid for it: 59 of 411 stored
  citations quoted the text verbatim at the wrong line. Turning them back on and re-running the
  same task moved coordinate corrections from 21.4% to 0.0% (15 of 70, then 0 of 39; P = 8.2e-05
  against the prior rate). Read that as a proportion, not a paired experiment — the second run
  planned a different outline, so it is 11 artifacts against 6 and the citation counts differ. The
  rule is which string goes where — the rendered text to the model, the raw file to the verifier —
  and the guide now says so under its own heading.

• The README's Status section no longer restates the current release. It had fallen five
  versions behind while claiming to describe the current one. It now points at the Releases page
  and this file and keeps only what does not change with a version number. That file is the PyPI
  long description, so the stale text was the first thing a reader saw.

v1.8.1 — the notes that were one commit past the tag

Documentation and tests only. No behaviour change, no API change — every 1.8.0 call path is
byte-identical. Upgrade only if you want the notes below in help().

budget_exhausted now documents what establishes it, and what it cannot answer

1.8.0 shipped that field with its evidence resting entirely on ScriptedInterpreter — which proves
dspy writes the forced-final marker and the kit reads it back, and says nothing about whether
the real sandbox path reaches that branch the same way.

A consumer ran all three states against dspy.PythonInterpreter on deno 2.8.2 — scripting only the
LM, since the interpreter is the seam that matters — and the field discriminated. The docstring now
records that, plus the two traps that fake a negative result:

• the forced-final path makes a second LM call for the task's own output field, so a scripted LM
  one turn short dies in extract, aforward raises, no final is recorded, and the marker looks
  lost when it is not;
• a True without a submitting control run is not a measurement — a field that is always True
  produces exactly that output.

And the boundary that is a product fact rather than a defect: the trajectory is written after
aforward() returns, so a SIGKILLed job — the case an operator actually asks about — is exactly the
one this reports None for.

These notes were one commit past the v1.8.0 tag. Anyone who installed 1.8.0 and ran help()
on the field saw none of them. That is the code-versus-docs failure this project keeps finding,
inverted: the documentation was correct in the repository and absent from what people install.
Caught by a consumer that checked the installed package before writing "the kit documents this" into
its own README, instead of trusting the sentence it was about to repeat.

The forced-final test had no control run

It asserted only that a run which never submits carries the marker — which a dspy that wrote that
string on every run would also satisfy. It now drives a submitting run and requires the marker
to be absent there. Verified additive by deletion: removing the control leaves the suite green, so
it guards something no other assertion reaches.

Full changelog: v1.8.0...v1.8.1

v1.8.0 — the facts a rubric needs, computed once

The kit now computes the generic half of a rubric's facts, so a consumer supplies only its domain
half. Three new public names, one optional payload field, nothing removed or re-typed.

The middle stage of a pipeline that was missing

rubric.py has always given you the SHAPE of a rubric — criteria_facts(criteria, facts, lens) is
pure and knows nothing about traces, and the category label stays opaque. What it never gave you
was the facts:

events ──▶ [ compute the facts ] ──▶ [ slice through a lens ] ──▶ CriterionFact
             ↑ everyone hand-wrote this      ↑ already here, already pure

compute_run_facts(events) fills it, emitting exactly RUN_FACT_KEYS — import that tuple rather
than hand-copying names. compute_run_facts_by_run for a file holding several runs.

facts = {**compute_run_facts(load_events(path, run_id)), **my_domain_facts(events)}
per_criterion = criteria_facts(my_criteria, facts, MY_LENS)

RUN_FACT_KEYS is closed and public on purpose: it is what the dict is BUILT against, so a key
shaped like a score cannot reach a consumer's dataset without a diff to a SemVer-governed name.

Two facts nothing computed before

budget_exhausted — did the run stop because its iteration budget ran out? Read from the marker
dspy writes on its own fall-through branch, which the kit has always recorded. No configured cap has
to be staged into the trace, it works on every trace ever written, and it avoids the
main_steps >= cap false positive on a run that submits successfully on its last allowed turn.
Tri-state: None, never False, when the answer is unknown.

fence_refused_turns — turns dspy refused to execute over a markdown fence tag. Named for the
mechanism, because the obvious cause is wrong, and shipping the wrong name would have been the
expensive part. Across three real corpora, 60 of 60 refusals had the fence buried rather than
leading, and 55 of the 60 are valid Python assigning a documentation page whose text contains a
fenced example — markdown = """# Overview … ```bash … """. dspy's stripper scans the whole cell
including string literals. So the number counts environment friction, not a model failing to follow
a format. One consumer read it the other way and spent two prompt generations suppressing the code
blocks its own pages needed.

Optional snapshot into the trace, OFF by default

TraceRecorder(record_metrics=True) or RLM_TRACE_METRICS=1 folds the facts into
run_end.payload["metrics"] — additive within trace/v1. Computed by re-reading the file just
written and filtered by run_id, so the snapshot is consistent-by-construction with the bytes
beside it, and emitted only when that re-read finds this run's own run_start — an all-zero
dict would be indistinguishable from a measured zero, which is 1.7.0's invariant one layer down.
run_end is recorded from a finally, so a BaseException during the snapshot cannot lose it.

Off by default because it changes what a trace CONTAINS, and because those payloads carry the
escalation prompt. compute_run_facts(events) is the authority in every case; the snapshot is a
convenience for a reader that will not call it.

Unmeasured is not zero

tool_wasted_seconds and tool_total_seconds are None, never 0.0, when nothing carried a
duration — and a measured zero stays 0.0. tool_measured_calls rides alongside because one
measured call in fifty is otherwise indistinguishable from fifty in fifty. Both rates are None on
a run with no turns, and fence_refused_turns: 0 there is unmeasured rather than measured-zero.

Internals worth knowing

_dspy_compat gains three names, and they are deliberately not symmetric. The accepted-fence-tag
set is a real dspy module constant, so its test asserts the introspection path resolves rather
than a value the fallback would satisfy anyway. The forced-final marker is a bare literal with
nothing behind it, so its test drives a real forced-final run instead of asserting the kit against
itself. And the fence decision is a declared verbatim mirror of a _-private dspy parser,
cross-checked against that function itself over a 36-row adversarial table: a regex shortcut was
measured at 1,764 disagreements and 3,855 crashes over 20,016 cells, so every line of the mirror is
load-bearing and individually pinned.

Full changelog: v1.7.0...v1.8.0

v1.7.0 — an escalation nobody recorded is one nobody can count

Every sub-LM escalation is now traced automatically, and the sub-LM wrapper hands dspy back the
response shape dspy handed it. No new public name; trace/v1 gains no event type, envelope
key, or payload field.

An escalation nobody recorded is one nobody can count

CLAUDE.md has always stated that a sub-LM call "is recorded as a sub_call". It was true only
when the consumer remembered to call intercept_sub_lm — a plain dspy.LM is invoked by dspy
directly and recorded nothing.

Surveyed across a fleet of nine consumers, four never wrapped, and two of those had corpora —
141 traces — in which sub_call was identically zero. That is indistinguishable from "measured,
and the model never escalated", and reading it as the second is a mistake this project has already
made: a decision to defer a speculation engine cited the zero as evidence of no escalation. The
real rate, re-derived from what the model actually wrote, was 0.15% — and one of those calls later
proved to be a 235.5-second escalation. An absent event is not a measurement.

RLMTask now wraps a plain sub_lm at the same per-run seam that binds the recorder. Nothing to
change on the consumer side. intercept_sub_lm keeps its real job — pass validators /
postprocessors for a deterministic validate/post-process pipeline — and a consumer with its own
recording wrapper opts out by declaring records_sub_call = True on it.

The bug that made auto-wrapping unsafe until it was fixed

intercept_sub_lm collapsed anything non-list into [outputs]. dspy's RLM._query_lm accepts
two shapes — a typed LMResponse or the legacy list[str | dict] — so a typed response became
[LMResponse] and dspy raised Sub-LM response must contain text, got LMResponse.

Invisible on the default path, reproducible under dspy.context(experimental=True), and on a
clock: dspy's own source says "In DSPy 3.3 and 3.4, ordinary calls preserve the legacy public
return value." The assumption had a two-minor shelf life and no test could see it expire, because
the convention was encoded at the call site instead of in _dspy_compat. It is resolved there now,
with a test that pins dspy's contract so the next change goes red in this repo.

Two rules that shim encodes, both found by adversarial review rather than by a failure:

• an unrecognised shape is handed back untouched so dspy raises its own error — inventing [""]
  converts a loud failure into a silent empty completion that reaches the planner and then the RL
  data as a real escalation answer;
• substituting text into an LMResponse drops the output's later text parts, because
  LMOutput.text joins them — replacing only the first left the rest appended ("AB" round-tripping
  to "ABB").

model_as_tool carried the identical defect sixty lines away and is fixed in the same place.

What changes for a trace you already have

• Traces from a consumer that never wrapped gain sub_call events, carrying the escalation
  prompt (input, truncated to 4,000 chars). A corpus spanning the upgrade is not homogeneous;
  run_start.rlm_harness separates it.
• metrics.compute_run_utilization's sub_calls_total moves from an unmeasurable zero to a count,
  and export_actions gains kind="sub" records — the point of the change, since an RL trainer
  doing credit assignment previously could not see an escalation that happened.
• A duck-typed sub-LM returning a bare str now fails where it used to work; one deriving from
  dspy.LM is unaffected.

Full changelog: v1.6.1...v1.7.0

v1.6.1 — fix the measurement 1.6.0 shipped

Two correctness fixes in shipped code. No new public name, no new payload field, no schema change.

A turn's timestamp could come from an earlier turn — and it reached a rendered UI

dspy wraps parse with with_callbacks once per class that defines it, and this kit's own
runtime._LenientJSONAdapter.parse calls super().parse(...). So under the default adapter
(config.adapter == "json") every root turn fired task._MainStepTimer twice with identical
outputs, where the stock JSONAdapter fires once. trace.record_main_trajectory matches a turn to
its live stamp by reasoning, so the surplus stamp was claimable by any later turn repeating
that string — which a retry loop does.

Measured across 85 real traces: all 12 with a ts inversion had a duplicated reasoning, none of
the 58 with unique reasoning did, and 2.1% of per-turn deltas came out negative. A consumer
rendered one as a −338.7s turn duration.

The turn before an inversion is skewed by the same stamp but looks plausible, so it hides. A
consumer can suppress the nonsense value; it can never find the plausible-but-wrong one. That is
why this is fixed where the stamp is made.

_MainStepTimer now stages the outermost parse only, via a per-thread depth from the public
on_adapter_parse_start/on_adapter_parse_end pair. If a future dspy stops firing the start hook,
behaviour degrades to exactly what it was before — never to staging nothing.

A matcher-side fix was tried and rejected. A forward-only cursor repairs non-adjacent
duplicates (27 of 32 in the corpus) but cannot repair adjacent ones (5 of 32): there it only stops
the delta going negative while the stamp stays ~0.1s wrong, trading a loud failure for a silent
one. It ships anyway as defence in depth — _match_ts and _match_exec both scan forward only
now — but it is not the fix.

verify_quote refused correct citations at non-word junctions

Whitespace runs were joined with \s+ uniformly, so a quote that reflowed a line break beside a
delimiter failed even though the citation was exact. The joiner is junction-aware now: \s+
between two word characters, \s* elsewhere. foo bar still cannot verify against foobar — the
false-positive direction stays closed, because an invented claim passing is worse than a real one
refused. Word-ness uses Python's Unicode \w, so 你好 世界 keeps requiring its space; an
ASCII class would have silently started accepting it.

Found by inspection, not by a failure: across ~479 real citations the old and new rules never
disagreed.

Two observable changes, both schema-legal

• exec_duration_s can be absent where it was present, and a ts can fall back to flush time
  where it was a live stamp. Both fields are optional in trace/v1; a consumer tracking coverage
  will see the number move.
• verify_quote can report an earlier occurrence — a . b against a.b ... a . b reported
  char 8 and now reports char 0. The line number is often unchanged, so a line-level check will
  not see it.

Docs

New "Reading a trace — the ordering rules" section, written because a downstream consumer read
these traces, concluded "sort by ts", and reordered its turns. main_step events are written in
one block after the run (so a tool_call precedes them in file order while being chronologically
later — 70 of 76 traces); payload["turn"] is authoritative and file order already matches it
(72 of 72); ts places turns against tool calls and nothing else.

Also corrects the claim that every local tool is sub-millisecond: make_grep_files_tool ships
per_match_timeout_s=1.0 and max_total_time_s=30.0. It stays untimed on a measurement
instead — n=146, median 0.029s, max 0.746s, not one call over a second — with the two caveats that
would reopen it now written beside it.

Full changelog: v1.6.0...v1.6.1