fix(models): warn on silent-empty truncation, track cost, fix flag

Author: ctrl-gaurav

effgen/core/agent_generation.py

@@ -145,8 +145,10 @@ def _apply_structured_output(
         if outcome.success and outcome.json_str is not None:
             response.output = outcome.json_str
             response.metadata["structured_output"] = True
-            # Preserve the historical flag for any consumer that checks it.
-            response.metadata["structured_output_reprompted"] = outcome.attempts > 0
+            # True only when a text reprompt actually ran — grammar/native
+            # constraint attempts also count toward `attempts` but are not a
+            # reprompt, so `attempts > 0` alone would mislabel them as one.
+            response.metadata["structured_output_reprompted"] = outcome.method == "reprompt"
             if output_model is not None:
                 response.metadata["parsed"] = self._parse_with_pydantic(
                     output_model, outcome.parsed,
@@ -533,7 +535,9 @@ def _warn_reasoning_budget(self, max_tokens: int | None, structured_output: bool
             kind, hint = "tight_budget", (
                 f"'{name}' is a reasoning model with max_tokens={max_tokens} — it can "
                 f"spend the whole budget on hidden reasoning and return no visible "
-                f"text. Consider max_tokens>={min_tokens}."
+                f"text. Consider max_tokens>={min_tokens}. This can happen even at "
+                f"temperature=0: the reasoning-token allocation is provider-controlled "
+                f"and is not made deterministic by a fixed temperature."
             )
 
         warn_key = (name, kind)

effgen/models/base.py

@@ -8,13 +8,16 @@
 from __future__ import annotations
 
 import functools
+import logging
 import time
 from abc import ABC, abstractmethod
 from collections.abc import Iterator
 from dataclasses import dataclass
 from enum import Enum
 from typing import Any, Literal
 
+logger = logging.getLogger(__name__)
+
 
 class ModelType(Enum):
     """Enumeration of supported model types."""
@@ -68,7 +71,15 @@ class GenerationConfig:
 
 @dataclass
 class GenerationResult:
-    """Result from a generation call."""
+    """Result from a generation call.
+
+    On a reasoning model, ``text`` can be empty even on a normal (non-error)
+    return: the output-token budget is spent on hidden reasoning before any
+    visible token is emitted. This is reported as ``finish_reason == "length"``
+    and ``metadata["truncated"] is True`` — check either before trusting an
+    empty ``text``/``str(result)``, or call through :class:`~effgen.core.agent.Agent`
+    instead, which already raises a clear error in that case.
+    """
     text: str
     tokens_used: int
     finish_reason: str
@@ -126,6 +137,53 @@ def _stamp_latency(result: Any, elapsed_s: float) -> Any:
     return result
 
 
+def _stamp_cost(model: "BaseModel", result: Any) -> None:
+    """Accumulate this call's cost onto the model instance's running total.
+
+    Populates ``metadata["total_cost"]`` via presence check, so an adapter that
+    already tracks its own cumulative total (OpenAI, Gemini, Anthropic) keeps
+    its own bookkeeping untouched; every other adapter gets the same
+    cumulative-cost field for free, derived from the ``cost_usd`` it already
+    reports per call. Skipped when the result carries no ``cost_usd`` (e.g.
+    local engines that do not price calls).
+    """
+    if not isinstance(result, GenerationResult):
+        return
+    meta = result.metadata
+    if meta is None or "total_cost" in meta:
+        return
+    cost = meta.get("cost_usd")
+    if cost is None:
+        return
+    model.total_cost = getattr(model, "total_cost", 0.0) + cost
+    meta["total_cost"] = model.total_cost
+
+
+def _warn_if_silently_empty(model: "BaseModel", result: Any) -> None:
+    """Log a warning when a reasoning model's raw ``generate()`` call returns
+    empty text because its output budget was spent on hidden reasoning before
+    any visible token (``finish_reason == "length"``).
+
+    :class:`~effgen.core.agent.Agent` already detects and escalates this case;
+    a caller using ``model.generate()`` directly has no such safety net, so an
+    empty ``GenerationResult`` would otherwise look like a working call that
+    produced nothing.
+    """
+    if not isinstance(result, GenerationResult):
+        return
+    if result.text or result.finish_reason != "length":
+        return
+    from ._adapter_utils import needs_reasoning_headroom
+    if not needs_reasoning_headroom(model):
+        return
+    logger.warning(
+        "%s returned empty text after exhausting its token budget on internal "
+        "reasoning (finish_reason='length'). Increase max_tokens, or check "
+        "metadata['truncated'] before trusting an empty result.",
+        getattr(model, "model_name", model.__class__.__name__),
+    )
+
+
 def _preflight_budget_check(model: "BaseModel") -> None:
     """Refuse to start a call when a configured budget is already at or over its cap.
 
@@ -151,7 +209,10 @@ def wrapper(self, *args, **kwargs):
         _preflight_budget_check(self)
         start = time.perf_counter()
         result = func(self, *args, **kwargs)
-        return _stamp_latency(result, time.perf_counter() - start)
+        result = _stamp_latency(result, time.perf_counter() - start)
+        _stamp_cost(self, result)
+        _warn_if_silently_empty(self, result)
+        return result
     wrapper.__effgen_timed__ = True
     return wrapper
 
@@ -173,6 +234,8 @@ def wrapper(self, *args, **kwargs):
         if isinstance(results, list):
             for r in results:
                 _stamp_latency(r, elapsed)
+                _stamp_cost(self, r)
+                _warn_if_silently_empty(self, r)
         return results
     wrapper.__effgen_timed__ = True
     return wrapper
@@ -379,6 +442,18 @@ def is_loaded(self) -> bool:
         """
         return self._is_loaded
 
+    def get_total_cost(self) -> float:
+        """Cumulative cost (USD) charged to this model instance since it was
+        created or since :meth:`reset_cost` was last called. Populated from
+        each call's ``cost_usd``; local/unpriced engines stay at ``0.0``.
+        """
+        return getattr(self, "total_cost", 0.0)
+
+    def reset_cost(self) -> None:
+        """Reset this instance's cumulative cost counter (see
+        :meth:`get_total_cost`) back to zero."""
+        self.total_cost = 0.0
+
     def get_metadata(self) -> dict[str, Any]:
         """
         Get model metadata and information.

tests/unit/test_agent.py

@@ -200,6 +200,9 @@ def test_warn_reasoning_budget_fires_for_tight_pinned_budget(self, mock_model, c
         with caplog.at_level(logging.WARNING, logger="effgen.core.agent_generation"):
             agent.run("test", max_tokens=250)
         assert any("reasoning model" in r.message for r in caplog.records)
+        # The hint also sets expectations about temperature=0 on a tight
+        # budget: it does not make reasoning-budget exhaustion deterministic.
+        assert any("temperature=0" in r.message for r in caplog.records)
 
     def test_warn_reasoning_budget_silent_for_non_reasoning_model(self, mock_model, caplog):
         import logging

tests/unit/test_generation_latency.py

@@ -12,6 +12,8 @@
 import time
 from collections.abc import Iterator
 
+import pytest
+
 from effgen.models.base import (
     BaseModel,
     GenerationConfig,
@@ -79,6 +81,61 @@ def generate(self, prompt, config=None, **kwargs):
         )
 
 
+class _PricedEngine(_TinyEngine):
+    """An engine that reports a per-call ``cost_usd`` but no cumulative total —
+    mirrors adapters (Groq, Cerebras, Together, Fireworks, Replicate) that price
+    each call without tracking a running total themselves."""
+
+    def __init__(self, cost_usd: float):
+        super().__init__()
+        self._cost_usd = cost_usd
+
+    def generate(self, prompt, config=None, **kwargs):
+        return GenerationResult(
+            text="x", tokens_used=1, finish_reason="stop", model_name=self.model_name,
+            metadata={"cost_usd": self._cost_usd},
+        )
+
+
+class _SelfTrackedCostEngine(_TinyEngine):
+    """An engine that already tracks its own cumulative ``total_cost`` (like the
+    OpenAI/Gemini/Anthropic adapters) — the generic accumulator must not touch it."""
+
+    def __init__(self):
+        super().__init__()
+        self.total_cost = 0.0
+
+    def generate(self, prompt, config=None, **kwargs):
+        cost = 0.01
+        self.total_cost += cost
+        return GenerationResult(
+            text="x", tokens_used=1, finish_reason="stop", model_name=self.model_name,
+            metadata={"cost_usd": cost, "total_cost": self.total_cost},
+        )
+
+
+class _ReasoningEngine(_TinyEngine):
+    """An engine named like a reasoning model that can return empty text when
+    ``finish_reason == "length"`` — mimics gpt-5*/o-series exhausting the token
+    budget on hidden reasoning before any visible token."""
+
+    def __init__(self, *, empty: bool):
+        super().__init__()
+        self.model_name = "gpt-5-nano"
+        self._empty = empty
+
+    def generate(self, prompt, config=None, **kwargs):
+        if self._empty:
+            return GenerationResult(
+                text="", tokens_used=500, finish_reason="length",
+                model_name=self.model_name, metadata={},
+            )
+        return GenerationResult(
+            text="hi", tokens_used=5, finish_reason="stop",
+            model_name=self.model_name, metadata={},
+        )
+
+
 def test_generate_stamps_latency():
     r = _TinyEngine().generate("hi")
     assert "latency_ms" in r.metadata and "duration_s" in r.metadata
@@ -119,3 +176,96 @@ def test_wrapping_is_idempotent_across_subclassing():
     # wrapped (the marker prevents re-wrapping an already-timed method).
     assert getattr(_TinyEngine.generate, "__effgen_timed__", False) is True
     assert getattr(_SelfTimedEngine.generate, "__effgen_timed__", False) is True
+
+
+# --------------------------------------------------------------------------- #
+# cumulative total_cost, extended to every adapter (not just OpenAI/Gemini/
+# Anthropic, which already tracked it themselves)
+# --------------------------------------------------------------------------- #
+
+
+def test_generate_accumulates_total_cost_across_calls():
+    engine = _PricedEngine(cost_usd=0.001)
+    r1 = engine.generate("a")
+    r2 = engine.generate("b")
+    assert r1.metadata["total_cost"] == 0.001
+    assert r2.metadata["total_cost"] == pytest.approx(0.002)
+    assert engine.get_total_cost() == pytest.approx(0.002)
+
+
+def test_reset_cost_zeroes_the_running_total():
+    engine = _PricedEngine(cost_usd=0.001)
+    engine.generate("a")
+    engine.reset_cost()
+    assert engine.get_total_cost() == 0.0
+    r = engine.generate("b")
+    assert r.metadata["total_cost"] == pytest.approx(0.001)
+
+
+def test_no_total_cost_when_engine_reports_no_cost():
+    # A local/unpriced engine has no cost_usd, so no fabricated total_cost key.
+    r = _TinyEngine().generate("hi")
+    assert "cost_usd" not in r.metadata
+    assert "total_cost" not in r.metadata
+
+
+def test_self_tracked_total_cost_is_not_double_counted():
+    # An adapter that already stamps its own cumulative total_cost (OpenAI,
+    # Gemini, Anthropic) keeps exactly its own number — the generic accumulator
+    # skips a result that already carries the key.
+    engine = _SelfTrackedCostEngine()
+    r1 = engine.generate("a")
+    r2 = engine.generate("b")
+    assert r1.metadata["total_cost"] == pytest.approx(0.01)
+    assert r2.metadata["total_cost"] == pytest.approx(0.02)
+
+
+def test_generate_batch_accumulates_total_cost_per_item():
+    class _PricedBatchEngine(_PricedEngine):
+        def generate_batch(self, prompts, config=None, **kwargs):
+            return [self.generate(p) for p in prompts]
+
+    engine = _PricedBatchEngine(cost_usd=0.001)
+    results = engine.generate_batch(["a", "b", "c"])
+    assert [r.metadata["total_cost"] for r in results] == [
+        pytest.approx(0.001), pytest.approx(0.002), pytest.approx(0.003),
+    ]
+
+
+# --------------------------------------------------------------------------- #
+# a silent-empty raw generate() on a reasoning model logs a visible warning
+# --------------------------------------------------------------------------- #
+
+
+def test_reasoning_model_empty_truncated_result_logs_warning(caplog):
+    import logging
+
+    with caplog.at_level(logging.WARNING, logger="effgen.models.base"):
+        r = _ReasoningEngine(empty=True).generate("say hi")
+    assert r.text == ""
+    assert any(
+        "exhausting its token budget on internal reasoning" in rec.message
+        for rec in caplog.records
+    )
+
+
+def test_reasoning_model_non_empty_result_does_not_warn(caplog):
+    import logging
+
+    with caplog.at_level(logging.WARNING, logger="effgen.models.base"):
+        r = _ReasoningEngine(empty=False).generate("say hi")
+    assert r.text == "hi"
+    assert not any(
+        "exhausting its token budget" in rec.message for rec in caplog.records
+    )
+
+
+def test_non_reasoning_model_empty_truncated_result_does_not_warn(caplog):
+    import logging
+
+    with caplog.at_level(logging.WARNING, logger="effgen.models.base"):
+        r = _LengthTruncatedEngine().generate("hi")
+    assert r.text == ""
+    assert not any(
+        "exhausting its token budget" in rec.message for rec in caplog.records
+    )

tests/unit/test_structured_output_robustness.py

@@ -264,6 +264,21 @@ def test_agent_surfaces_attempts_on_success():
     assert resp.metadata["structured_output"] is True
     assert resp.metadata["structured_output_attempts"] == 1
     assert resp.metadata["structured_output_method"] == "native"
+    # A single native-JSON-mode call is not a reprompt: attempts > 0 alone
+    # would mislabel this as a repair loop that never ran.
+    assert resp.metadata["structured_output_reprompted"] is False
+
+
+def test_agent_reprompted_flag_true_only_for_the_reprompt_fallback():
+    # No native JSON support (_PlainModel) forces the reprompt fallback; the
+    # first reprompt attempt succeeds, so method == "reprompt" and the flag
+    # accurately reports that a repair loop ran.
+    agent = _agent_with(_PlainModel([VALID]))
+    resp = agent._apply_structured_output(_response("some prose"), SCHEMA, None, "capital?")
+    assert resp.success is True
+    assert resp.metadata["structured_output_method"] == "reprompt"
+    assert resp.metadata["structured_output_attempts"] == 1
+    assert resp.metadata["structured_output_reprompted"] is True
 
 
 def test_agent_fast_path_zero_attempts_when_answer_already_valid():