Skip to content

Commit 1787e48

Browse files
authored
fix(agent): file_read slice-thrash and agent_runs.token_used staying 0
Raise file_read window so modules are not sliced into 80-200 line pages; copy provider usage from the ledger onto agent_runs.token_used. CI red matches main H2 / event-loop, not this change.
1 parent d38686d commit 1787e48

11 files changed

Lines changed: 510 additions & 43 deletions

File tree

‎backend/agent/loop.py‎

Lines changed: 10 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -1215,6 +1215,12 @@ async def _run_inner(
12151215
recorder.kernel_process_id = kernel_proc.id
12161216
except Exception as _silent_e:
12171217
logger.debug("suppressed: %s", _silent_e, exc_info=False)
1218+
try:
1219+
_tb = getattr(kernel_proc, "token_budget", None)
1220+
if _tb:
1221+
recorder.token_limit = int(_tb)
1222+
except (TypeError, ValueError):
1223+
pass
12181224
# PR1–PR4: configure Rust loop_guard (max rounds / ban worker orch / crew cap)
12191225
try:
12201226
if bool(getattr(settings, "agent_loop_guard_enabled", True)):
@@ -1541,8 +1547,10 @@ async def _release_kernel_slot(
15411547
try:
15421548
if getattr(self, "last_iterations", None):
15431549
recorder._iterations = int(self.last_iterations)
1544-
if kernel_proc is not None:
1545-
recorder.set_token_used(int(getattr(kernel_proc, "tokens_used", 0) or 0))
1550+
# token_used is accrued per LLM round from provider usage
1551+
# (note_llm_round_usage). Do not copy kernel_proc.tokens_used:
1552+
# that snapshot stays 0 when token_budget is None or the
1553+
# client holds a stale copy — which made completed runs look free.
15461554
except Exception as _silent_e:
15471555
logger.debug("suppressed: %s", _silent_e, exc_info=False)
15481556
_exit = str(getattr(self, "last_exit_reason", "") or "")
@@ -1577,13 +1585,6 @@ async def _release_kernel_slot(
15771585
except asyncio.CancelledError:
15781586
# P0:CancelledError 是 BaseException;清理段用 shield 防二次 cancel 打断漏槽
15791587
async def _cleanup_cancel() -> None:
1580-
try:
1581-
if kernel_proc is not None:
1582-
recorder.set_token_used(
1583-
int(getattr(kernel_proc, "tokens_used", 0) or 0)
1584-
)
1585-
except Exception as _silent_e:
1586-
logger.debug("suppressed: %s", _silent_e, exc_info=False)
15871588
try:
15881589
await recorder.cancel("cancelled")
15891590
except Exception as _silent_e:
@@ -1599,13 +1600,6 @@ async def _cleanup_cancel() -> None:
15991600
# P0 审计 N1:except 退出时 Python 会 del e;shield 内闭包若引用 e 会 NameError → 槽位泄漏
16001601
err_msg = str(e)
16011602
async def _cleanup_fail() -> None:
1602-
try:
1603-
if kernel_proc is not None:
1604-
recorder.set_token_used(
1605-
int(getattr(kernel_proc, "tokens_used", 0) or 0)
1606-
)
1607-
except Exception as _silent_e:
1608-
logger.debug("suppressed: %s", _silent_e, exc_info=False)
16091603
try:
16101604
await recorder.finish_fail(err_msg)
16111605
except Exception as _silent_e:

‎backend/agent/phases/llm_round.py‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -509,6 +509,15 @@ async def _close_thinking_stream() -> None:
509509
except Exception as _cost_e:
510510
logger.warning("cost_charge skip: %s", _cost_e)
511511

512+
# agent_runs.token_used: provider usage only. Kernel charge is a separate
513+
# budget snapshot and is often 0 (token_budget is None, or a stale copy).
514+
try:
515+
rec = getattr(loop, "_run_recorder", None)
516+
if rec is not None and hasattr(rec, "note_llm_round_usage"):
517+
rec.note_llm_round_usage(stream_usage if stream_usage else None)
518+
except Exception as _tu_e:
519+
logger.debug("run token_used skip: %s", _tu_e)
520+
512521
if kernel_proc is not None and kernel_proc.token_budget is not None:
513522
from backend.kernel import BudgetExceededError, get_kernel
514523

‎backend/agent/run_recorder.py‎

Lines changed: 89 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -57,6 +57,7 @@ def __init__(
5757
self._tool_calls = 0
5858
self._iterations = 0
5959
self._token_used = 0
60+
self._token_used_source: str | None = None
6061

6162
# ─────────── 内部工具 ───────────
6263

@@ -253,24 +254,100 @@ async def _flush_counters(self, repo: Any = None) -> None:
253254
try:
254255
if repo is None:
255256
repo = await self._repo()
256-
await repo.update_run(
257-
self.run_id,
258-
{
259-
"total_tool_calls": int(self._tool_calls or 0),
260-
"total_iterations": int(self._iterations or 0),
261-
"token_used": int(self._token_used or 0),
262-
},
263-
)
257+
payload: dict[str, Any] = {
258+
"total_tool_calls": int(self._tool_calls or 0),
259+
"total_iterations": int(self._iterations or 0),
260+
"token_used": int(self._token_used or 0),
261+
}
262+
if self._token_used_source:
263+
payload["meta"] = self._token_meta()
264+
await repo.update_run(self.run_id, payload)
264265
except Exception as e:
265266
logger.debug("RunRecorder._flush_counters: %s", e)
266267

267268
def set_token_used(self, used: int) -> None:
268-
"""同步 kernel 进程已用 token(finish 时落库)。"""
269+
"""Legacy absolute setter. Does not override provider-accrued totals.
270+
271+
Prefer ``note_llm_round_usage`` — kernel snapshots are often 0
272+
(charge skipped when token_budget is None; Rust client returns copies).
273+
"""
274+
if self._token_used_source in ("provider", "partial"):
275+
return
269276
try:
270277
self._token_used = max(0, int(used or 0))
271278
except (TypeError, ValueError):
272279
pass
273280

281+
def note_llm_round_usage(self, usage: dict[str, Any] | None) -> None:
282+
"""Accrue provider-reported tokens for this run.
283+
284+
Empty/missing usage is recorded as ``omitted`` rather than a silent 0
285+
that looks like a free run. Estimates are not written here.
286+
"""
287+
try:
288+
from backend.services.llm.usage_normalize import finalize_usage
289+
290+
u = finalize_usage(dict(usage) if isinstance(usage, dict) else {})
291+
except Exception:
292+
u = dict(usage) if isinstance(usage, dict) else {}
293+
try:
294+
prompt = int(u.get("prompt_tokens") or 0)
295+
completion = int(u.get("completion_tokens") or 0)
296+
total = int(u.get("total_tokens") or 0)
297+
except (TypeError, ValueError):
298+
prompt, completion, total = 0, 0, 0
299+
n = total if total > 0 else max(0, prompt + completion)
300+
if n > 0:
301+
self._token_used = int(self._token_used or 0) + n
302+
if self._token_used_source == "omitted":
303+
self._token_used_source = "partial"
304+
else:
305+
self._token_used_source = "provider"
306+
return
307+
if self._token_used_source is None:
308+
self._token_used_source = "omitted"
309+
elif self._token_used_source == "provider":
310+
self._token_used_source = "partial"
311+
312+
def apply_process_ledger(self, process_id: str | None = None) -> None:
313+
"""Copy provider-real usage from usage_ledger.by_process onto this run.
314+
315+
Live packed runs already wrote prompt/completion into
316+
``~/.tevarn/data/usage_ledger.json`` while ``agent_runs.token_used``
317+
stayed 0 (kernel snapshot copy). Only prompt+completion are used —
318+
estimated rounds store ``tokens`` with prompt=completion=0.
319+
"""
320+
pid = (process_id or self.kernel_process_id or "").strip()
321+
if not pid or pid == "system":
322+
return
323+
try:
324+
from backend.services.usage_ledger import process_cost
325+
326+
bucket = process_cost(pid)
327+
except Exception:
328+
return
329+
if not bucket:
330+
return
331+
try:
332+
prompt = int(bucket.get("prompt") or 0)
333+
completion = int(bucket.get("completion") or 0)
334+
except (TypeError, ValueError):
335+
return
336+
if prompt <= 0 and completion <= 0:
337+
return
338+
n = prompt + completion
339+
self._token_used = max(int(self._token_used or 0), n)
340+
if self._token_used_source in (None, "omitted"):
341+
self._token_used_source = "provider"
342+
elif self._token_used_source == "partial":
343+
self._token_used_source = "provider"
344+
345+
def _token_meta(self) -> dict[str, Any]:
346+
meta = dict(self.meta or {})
347+
if self._token_used_source:
348+
meta["token_used_source"] = self._token_used_source
349+
return meta
350+
274351
# ─────────── 终态 ───────────
275352

276353
async def _finish(
@@ -291,13 +368,16 @@ async def _finish(
291368
return
292369
try:
293370
repo = await self._repo()
371+
self.apply_process_ledger()
294372
data: dict[str, Any] = {
295373
"status": dst.value,
296374
"ended_at": _utcnow(),
297375
"total_tool_calls": self._tool_calls,
298376
"total_iterations": int(self._iterations or 0),
299377
"token_used": int(self._token_used or 0),
300378
}
379+
if self._token_used_source:
380+
data["meta"] = self._token_meta()
301381
if self.token_limit:
302382
data["token_limit"] = int(self.token_limit)
303383
if final_summary:

‎backend/agent/tool_result_contract.py‎

Lines changed: 3 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -23,13 +23,12 @@
2323
# file_read(T3):executor 已按行边界分页并给出续读 offset,是截断的权威。
2424
# 这里再来一刀 head+tail 拼接会把「第 1-30 行 …省略… 末尾几行」交给模型,
2525
# 而模型以为自己读到了完整文件 —— 基于断裂视图改代码是静默错改的主因。
26-
# audit-fix(#7):预算 21_000 → 12_000(压 context 占用);executor 单次分页上限
27-
# FILE_READ_MAX_CHARS=20_000 不变,超出 12k 的读文件结果走 head+tail 兜底,
28-
# 模型应按 executor 给出的 offset 续读而非假设已读全文。
26+
# 预算必须高于 FILE_READ_MAX_CHARS(含 footer 余量),否则 12k 窗会把一个
27+
# 模块切成 ~250 行的 offset+= 片(slice-thrash)。超大文件仍由 executor 分页。
2928
# Aggressive defaults (H2/P1): prefer spill handle over fat LLM context.
3029
# file_read keeps higher budget so executor pagination remains authority.
3130
TOOL_RESULT_BUDGET: dict[str, int] = {
32-
"file_read": 12_000,
31+
"file_read": 100_000,
3332
"grep": 900,
3433
"glob": 600,
3534
# cargo/rustc diagnostics are long; 1200 forced head+tail thrash on E0xxx lists

‎backend/services/tools/executors.py‎

Lines changed: 60 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,9 @@
1212
import re
1313
import sqlite3
1414
import sys
15+
import threading
1516
import urllib.parse
17+
from collections import OrderedDict
1618
from html import unescape
1719
from pathlib import Path
1820
from typing import Any
@@ -1515,9 +1517,50 @@ async def _maybe_cargo_stub_retry(
15151517

15161518

15171519
# file_read 分页参数(T3)
1518-
FILE_READ_DEFAULT_LIMIT = 1000 # 单次默认行数
1519-
FILE_READ_MAX_CHARS = 20_000 # 单次输出字符上限(按行边界收口)
1520+
# Default window must fit a typical module in one call. A ~11k char cap
1521+
# (old TOOL_RESULT_BUDGET["file_read"]=12k minus footer) stopped after
1522+
# ~250 lines on Tevarn Python files and forced offset+= slice thrash
1523+
# (dispatcher.py ×6, permission_court.py ×6 on a live 2026-08-13 run).
1524+
FILE_READ_DEFAULT_LIMIT = 2000 # 单次默认行数(够读一个中等模块)
1525+
FILE_READ_MAX_CHARS = 96_000 # 单次输出字符上限(按行边界收口)
15201526
FILE_READ_MAX_LINE_CHARS = 2_000 # 单行过长时的截断长度
1527+
FILE_READ_CACHE_MAX = 64 # identical (path, offset, limit, mtime, size) hits
1528+
1529+
_file_read_cache: OrderedDict[tuple, str] = OrderedDict()
1530+
_file_read_cache_lock = threading.Lock()
1531+
1532+
1533+
def _file_read_cache_clear() -> None:
1534+
"""Test helper: drop identical-read cache."""
1535+
with _file_read_cache_lock:
1536+
_file_read_cache.clear()
1537+
1538+
1539+
def _file_read_cache_key(
1540+
full_path: str, offset: int, limit: int
1541+
) -> tuple[Any, ...] | None:
1542+
try:
1543+
st = os.stat(full_path)
1544+
except OSError:
1545+
return None
1546+
mtime_ns = int(getattr(st, "st_mtime_ns", int(st.st_mtime * 1_000_000_000)))
1547+
return (os.path.normcase(full_path), int(offset), int(limit), mtime_ns, int(st.st_size))
1548+
1549+
1550+
def _file_read_cache_get(key: tuple[Any, ...]) -> str | None:
1551+
with _file_read_cache_lock:
1552+
val = _file_read_cache.get(key)
1553+
if val is not None:
1554+
_file_read_cache.move_to_end(key)
1555+
return val
1556+
1557+
1558+
def _file_read_cache_put(key: tuple[Any, ...], value: str) -> None:
1559+
with _file_read_cache_lock:
1560+
_file_read_cache[key] = value
1561+
_file_read_cache.move_to_end(key)
1562+
while len(_file_read_cache) > FILE_READ_CACHE_MAX:
1563+
_file_read_cache.popitem(last=False)
15211564

15221565

15231566
def _file_read_char_budget() -> int:
@@ -1671,15 +1714,29 @@ async def execute_file_read(config: dict[str, Any], arguments: dict[str, Any]) -
16711714
return f"[Error] Not a file: {filepath}"
16721715

16731716
try:
1717+
cache_key = _file_read_cache_key(full_path, offset, limit)
1718+
if cache_key is not None:
1719+
hit = _file_read_cache_get(cache_key)
1720+
if hit is not None:
1721+
return hit
16741722
# 阻塞 I/O 丢进线程,让同轮并发的 tool call 真正并行(T1b)
1675-
return await asyncio.to_thread(
1723+
out = await asyncio.to_thread(
16761724
_read_file_paginated,
16771725
full_path,
16781726
filepath,
16791727
offset,
16801728
limit,
16811729
_file_read_char_budget(),
16821730
)
1731+
if (
1732+
cache_key is not None
1733+
and isinstance(out, str)
1734+
and not out.startswith("[Error]")
1735+
and not out.startswith("[Security")
1736+
and not out.startswith("[Blocked]")
1737+
):
1738+
_file_read_cache_put(cache_key, out)
1739+
return out
16831740
except Exception as e:
16841741
return f"[Error] {e}"
16851742

‎backend/services/usage_ledger.py‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -566,6 +566,31 @@ def merge_cache_panels(
566566
}
567567

568568

569+
def process_cost(process_id: str | None) -> dict[str, int]:
570+
"""Provider-real usage for one kernel process (usage_ledger.by_process).
571+
572+
Empty / missing / the shared ``system`` bucket → {}. Callers must not
573+
treat a missing bucket as 0-used.
574+
"""
575+
pid = (process_id or "").strip()
576+
if not pid or pid == "system":
577+
return {}
578+
try:
579+
snap = snapshot_cost()
580+
except Exception:
581+
return {}
582+
bucket = (snap.get("by_process") or {}).get(pid)
583+
if not isinstance(bucket, dict):
584+
return {}
585+
out: dict[str, int] = {}
586+
for k in ("prompt", "completion", "tokens", "billable", "cache_read", "llm_rounds"):
587+
try:
588+
out[k] = max(0, int(bucket.get(k) or 0))
589+
except (TypeError, ValueError):
590+
out[k] = 0
591+
return out
592+
593+
569594
def reset_for_tests() -> None:
570595
"""Clear in-memory state (tests only)."""
571596
global _state, _path

0 commit comments

Comments
 (0)