Два корня пустого spend за час: 1) usage-добыча в воркере смотрела m["message"]["usage"] — у strands usage живёт в message["metadata"]["usage"] (event_loop.py), поэтому usage всегда был пуст (тот же баг, что уже чинили в runtime._extract_usage). 2) BudgetSpent писал scheduler ПОСЛЕ успешного возврата воркера — таймаут убивал воркер раньше записи, spend терял весь тик. 3) Модель: strands_harness строит OpenAIResponsesModel, у 9router /responses — шим без usage (проверено: response.completed приходит без usage; non-stream возвращает chat-completion-объект). Перевёл на OpenAIModel (chat/completions, include_usage) — usage приходит и с инструментами, и в reasoning-режиме. Фикс: - воркер пишет BudgetSpent ИНКРЕМЕНТАЛЬНО после каждого модельного вызова (hook на MessageAddedEvent, assistant с metadata.usage, дедуп по объекту) — таймаут теряет максимум хвост текущего вызова, не весь тик; - _extract_usage: корректная структура + суммирование по шагам (model_calls); - scheduler дублирует запись только если воркер не смог разобрать usage; - события помечены source: worker|runner и trace_id тика. Проверено: дельты воркера == итоговый usage тика (39-шаговый тик сходится); убитый по таймауту тик сохраняет все завершённые шаги; spend виден в read model/dashboard.
322 lines
No EOL
15 KiB
Python
322 lines
No EOL
15 KiB
Python
"""Simbiot Harness — scheduler: тактовая лестница + cycle runners.
|
||
|
||
Правила:
|
||
- тик уровня идемпотентен (UNIQUE level:seq);
|
||
- один исполнитель на уровень → сериализация;
|
||
- занятый уровень поглощает тик (TickAbsorbed) и пишет
|
||
детерминированную дайджест-заглушку — без LLM;
|
||
- запущенная задача не прерывается.
|
||
"""
|
||
import json
|
||
import os
|
||
import time
|
||
import traceback
|
||
from datetime import datetime, timezone, timedelta
|
||
|
||
from . import es
|
||
from .levels import LEVELS
|
||
from . import runtime
|
||
from . import commands
|
||
from .commands import _ORDER
|
||
|
||
# интервал демона
|
||
POLL = 1.0
|
||
# уровни, включённые в v0.1 (порядок для лога)
|
||
ACTIVE = ["sec", "min", "hour", "day"]
|
||
|
||
# состояние исполнителей уровня: level → {"busy": bool, "task": id|None}
|
||
_runners = {}
|
||
# когда уровень последний раз слал TG-уведомление о занятости (анти-спам)
|
||
_NOTIFY_TS = {}
|
||
|
||
|
||
def _now():
|
||
return datetime.now(timezone.utc)
|
||
|
||
|
||
def _log(msg: str):
|
||
print(f"[{datetime.now().strftime('%H:%M:%S')}] {msg}", flush=True)
|
||
|
||
|
||
def tick_number(level_cfg, ts: int):
|
||
return ts // level_cfg.every
|
||
|
||
|
||
def emit_tick(level_cfg, seq: int):
|
||
"""CycleTicked идемпотентно. Возвращает True если это новый тик."""
|
||
r = es.append_tick(level_cfg.name, seq)
|
||
return r is not None
|
||
|
||
|
||
def deterministic_digest_stub(level_cfg, seq: int, reason: str):
|
||
"""Заглушка дайджеста для поглощённого тика — детерминированно, без LLM."""
|
||
period = datetime.fromtimestamp(seq * level_cfg.every, tz=timezone.utc)
|
||
es.append_event("cycle", f"stub:{level_cfg.name}:{seq}", "DigestWritten", {
|
||
"level": level_cfg.name,
|
||
"period": period.isoformat(),
|
||
"summary_ref": None,
|
||
"text": f"[absorbed:{reason}] уровень {level_cfg.name} был занят/пропущен; такт {seq}",
|
||
"stub": True,
|
||
})
|
||
|
||
|
||
def find_task(level_cfg, model: dict):
|
||
"""Ищет ready-задачу доступного классу уровня. Возвращает task_id или None."""
|
||
classes = level_cfg.task_classes
|
||
for tid, t in model["tasks"].items():
|
||
if t["status"] == "ready" and t.get("size") in classes:
|
||
return tid
|
||
return None
|
||
|
||
|
||
def _lvl_rank(name: str) -> int:
|
||
"""Ранг уровня в лестнице; неизвестный → ниже всех (эскалации ему не адресованы)."""
|
||
return _ORDER.index(name) if name in _ORDER else len(_ORDER)
|
||
|
||
|
||
def build_context(level_cfg, model: dict, task=None):
|
||
"""Сборка контекста тика: мандат + память уровня + выжимки нижних + задача."""
|
||
parts = [level_cfg.mandate]
|
||
|
||
# идентичность/цели v0.1 — статично из policy (если есть)
|
||
policy = model.get("policy")
|
||
if policy and policy.get("identity"):
|
||
parts.append("ИДЕНТИЧНОСТЬ: " + policy["identity"])
|
||
|
||
# выжимки нижних уровней: последние дайджесты
|
||
order = ["min", "hour", "day"]
|
||
idx = order.index(level_cfg.name) if level_cfg.name in order else 0
|
||
lower = order[:idx]
|
||
digests = []
|
||
for lvl in lower:
|
||
for key, d in model["digests"].items():
|
||
if d["level"] == lvl and not d.get("stub"):
|
||
digests.append(d)
|
||
digests.sort(key=lambda d: d["ts"], reverse=True)
|
||
if digests:
|
||
parts.append("ВЫЖИМКИ НИЖНИХ УРОВНЕЙ (последние, сжатые):")
|
||
for d in digests[:6]:
|
||
parts.append(f"- [{d['level']}] {d['text'][:400]}")
|
||
|
||
# эскалации: открытые, адресованные этому уровню и выше — в приоритете
|
||
escs = []
|
||
for e in (model.get("escalations") or {}).values():
|
||
if not isinstance(e, dict) or e.get("status") != "open" or e.get("stub"):
|
||
continue
|
||
to_level = e.get("to_level", "day")
|
||
if to_level not in _ORDER or _lvl_rank(level_cfg.name) < _lvl_rank(to_level):
|
||
continue
|
||
escs.append(e)
|
||
if escs:
|
||
escs.sort(key=lambda e: ({'critical': 0, 'warn': 1, 'info': 2}.get(e.get("severity"), 3),
|
||
e.get("ts", "")), reverse=False)
|
||
lines = []
|
||
for e in escs[:10]:
|
||
who = f"от {e.get('from_level')}" if e.get("from_level") else ""
|
||
lines.append(f"- [{e['id']}] ({e.get('severity','info')}) {who} → "
|
||
f"{e.get('to_level')}: {e.get('reason','')[:300]}"
|
||
+ (f"\n контекст: {e.get('context','')[:400]}" if e.get("context") else ""))
|
||
parts.append("ЭСКАЛАЦИИ (важное с нижних уровней; отработай и закрой: "
|
||
"./venv/bin/python cli.py escalation-ack <id>):\n" + "\n".join(lines))
|
||
|
||
# инбокс: входящие TG-сообщения, ждущие ответа (в приоритете)
|
||
inbox = [m for m in (model.get("inbox") or {}).values()
|
||
if not m.get("replied") and not m.get("ignored") and m.get("text")]
|
||
if inbox:
|
||
lines = []
|
||
for m in inbox[:10]:
|
||
m_id = "m-" + str(m.get("update_id"))
|
||
who = m.get("username") or m.get("first_name") or m.get("user_id")
|
||
lines.append(f"- [{m_id}] от {who}: {m['text'][:300]}")
|
||
parts.append("ВХОДЯЩИЕ СООБЩЕНИЯ (ответь через: ./venv/bin/python cli.py tg-reply <id> \"текст\"):\n" + "\n".join(lines))
|
||
|
||
# доска задач
|
||
tasks = [t for t in model["tasks"].values() if t["status"] in ("ready", "running")]
|
||
if tasks:
|
||
lines = [f"- {t['id']}: {t['title'][:80]} [{t['size']}] {t['status']}" for t in tasks[:15]]
|
||
parts.append("ДОСКА ЗАДАЧ:\n" + "\n".join(lines))
|
||
|
||
if task:
|
||
parts.append(f"ТЕКУЩАЯ ЗАДАЧА: {task['id']}: {task['title']}\nВыполни её и выдай результат.")
|
||
|
||
return "\n\n".join(parts)
|
||
|
||
|
||
def _notify_busy(level_cfg, task):
|
||
"""TG-visibility: уровни сами сообщают о занятости.
|
||
|
||
Анти-спам: по одному уведомлению на уровень не чаще раза в 15 минут —
|
||
повторные взятия задач внутри часа не заспамят чат.
|
||
"""
|
||
global _NOTIFY_TS
|
||
now = time.time()
|
||
if now - _NOTIFY_TS.get(level_cfg.name, 0) < 900: # 15 минут
|
||
return
|
||
_NOTIFY_TS[level_cfg.name] = now
|
||
from . import tg_inbox
|
||
tg_inbox.notify_chat(
|
||
f"🔧 Уровень {level_cfg.name} взял задачу [{task.get('size', '?')}] "
|
||
f"«{task.get('title', '')[:70]}»\n"
|
||
f"Срез лестницы по запросу: /лестница"
|
||
)
|
||
|
||
|
||
def run_level_tick(level_cfg, seq: int, model: dict):
|
||
"""Один тик уровня с LLM: дайджест + (опц.) задача. Возвращает текст.
|
||
|
||
LLM-тик гоняется в изолированном сабпроцессе (isolated_runner):
|
||
у Strands глобальный asyncio-рантайм, второй create_harness()
|
||
в том же процессе валит его («cannot schedule new futures»).
|
||
"""
|
||
from . import isolated_runner
|
||
|
||
task_id = find_task(level_cfg, model)
|
||
task = model["tasks"].get(task_id) if task_id else None
|
||
if task:
|
||
es.append_event("task", task_id, "TaskClaimed", {
|
||
"level": level_cfg.name, "session_id": f"s-{level_cfg.name}-{seq}",
|
||
})
|
||
# TG-visibility: взяли задачу — сообщаем в чат (анти-спам: не чаще 15м на уровень)
|
||
try:
|
||
from . import tg_inbox
|
||
_notify_busy(level_cfg, task)
|
||
except Exception:
|
||
pass # уведомление — best effort, не валить тик
|
||
prompt = build_context(level_cfg, model, task)
|
||
text, usage, trace_id = isolated_runner.run_llm_tick(
|
||
level_cfg, prompt,
|
||
session_id=f"s-{level_cfg.name}-{seq}",
|
||
trace_prefix=f"{level_cfg.name}-{seq}",
|
||
)
|
||
if text is None:
|
||
# воркер упал — задача не выполнена, откатываем claim
|
||
if task:
|
||
es.append_event("task", task_id, "TaskFailed", {
|
||
"error": str(usage.get("error", "llm worker failed"))[:500],
|
||
})
|
||
raise RuntimeError(str(usage.get("error", "llm worker failed")))
|
||
# дайджест тика
|
||
period = datetime.fromtimestamp(seq * level_cfg.every, tz=timezone.utc)
|
||
es.append_event("cycle", f"digest:{level_cfg.name}:{seq}", "DigestWritten", {
|
||
"level": level_cfg.name, "period": period.isoformat(),
|
||
"summary_ref": trace_id, "text": (text or "")[:2000],
|
||
})
|
||
# BudgetSpent воркер уже записал сам — инкрементально, после каждого
|
||
# модельного вызова (устраняет потерю spend при таймауте воркера).
|
||
# Если usage в результате пуст (воркер не смог разобрать историю —
|
||
# старый воркер / нетекстовая структура), дублируем итог, чтобы тик
|
||
# не терялся в spend вовсе: дедуп по trace_id в read model.
|
||
if usage and not usage.get("model_calls"):
|
||
es.append_event("harness", "budget", "BudgetSpent", {
|
||
"level": level_cfg.name, "trace_id": trace_id, "source": "runner",
|
||
**{k: v for k, v in usage.items() if k != "error"},
|
||
})
|
||
if task:
|
||
es.append_event("task", task_id, "TaskCompleted", {
|
||
"result_ref": trace_id, "answer": (text or "")[:2000],
|
||
})
|
||
return text, task_id
|
||
|
||
|
||
def process_level(level_cfg, model: dict):
|
||
"""Тик одного уровня: занят? → absorb; иначе работа."""
|
||
st = _runners.setdefault(level_cfg.name, {"busy": False, "task": None})
|
||
if st["busy"]:
|
||
seq = tick_number(level_cfg, int(time.time()))
|
||
deterministic_digest_stub(level_cfg, seq, "busy")
|
||
es.append_event("cycle", f"absorbed:{level_cfg.name}:{seq}", "TickAbsorbed",
|
||
{"level": level_cfg.name, "reason": "busy"})
|
||
return "absorbed"
|
||
|
||
seq = tick_number(level_cfg, int(time.time()))
|
||
if not emit_tick(level_cfg, seq):
|
||
return "already" # тик этого такта уже был (идемпотентность)
|
||
|
||
st["busy"] = True
|
||
try:
|
||
if not level_cfg.uses_llm:
|
||
# секундный уровень: детерминированный рефлекс без LLM
|
||
text, task_id = _reflex_tick(level_cfg, seq, model)
|
||
return f"reflex ok {task_id or ''}".strip()
|
||
text, task_id = run_level_tick(level_cfg, seq, model)
|
||
return f"ran (task={task_id or '-'})"
|
||
except Exception as e:
|
||
es.append_event("harness", "errors", "CycleError", {
|
||
"level": level_cfg.name, "error": str(e)[:1000],
|
||
"trace": traceback.format_exc()[-2000:],
|
||
})
|
||
# воркер LLM-тика умер — наверх, чтобы верхний уровень узнал сразу:
|
||
# нижний сам себя не чинит (контекст мал), фикс идёт сверху.
|
||
try:
|
||
import secrets as _secrets
|
||
esc_id = f"e-{datetime.now(timezone.utc).strftime('%y%m%d%H%M%S')}-{_secrets.token_hex(3)}"
|
||
es.append_event("harness", esc_id, "EscalationRaised", {
|
||
"id": esc_id, "from_level": level_cfg.name,
|
||
"to_level": commands.level_above(level_cfg.name) or "day",
|
||
"reason": f"тик {level_cfg.name} упал: {str(e)[:200]}",
|
||
"context": traceback.format_exc()[-1500:],
|
||
"severity": "warn", "task_id": None, "source": "scheduler",
|
||
})
|
||
except Exception:
|
||
pass # эскалация — best effort: не маскировать исходную ошибку
|
||
return "error: " + str(e)[:120]
|
||
finally:
|
||
st["busy"] = False
|
||
|
||
|
||
def _reflex_tick(level_cfg, seq: int, model: dict):
|
||
"""Секундный рефлекс: телеметрия + алерты, без LLM."""
|
||
import os
|
||
load = None
|
||
try:
|
||
load = os.getloadavg()[0]
|
||
except Exception:
|
||
pass
|
||
period = datetime.fromtimestamp(seq * level_cfg.every, tz=timezone.utc)
|
||
payload = {"level": "sec", "seq": seq, "load1": load,
|
||
"ts": period.isoformat()}
|
||
# алерт-порог из policy (по умолчанию 8 — как simbiotd)
|
||
thr = (model.get("policy") or {}).get("cpu_alert_threshold", 8)
|
||
if load is not None and load >= thr:
|
||
payload["alert"] = f"load {load:.2f} >= {thr}"
|
||
es.append_event("cycle", f"reflex:{seq}", "ReflexObserved", payload)
|
||
return payload, None
|
||
|
||
|
||
def main_loop():
|
||
"""Демон: уровни тикают независимо, каждый в своём потоке.
|
||
LLM-тик одного уровня больше не блокирует остальные
|
||
(раньше минутный тик замораживал и сек-рефлекс, и час)."""
|
||
import threading
|
||
|
||
es.init_db()
|
||
_log("Simbiot Harness запущен; уровни: " + ", ".join(ACTIVE))
|
||
last_seq = {}
|
||
threads = {}
|
||
while True:
|
||
for name in ACTIVE:
|
||
cfg = LEVELS[name]
|
||
seq = tick_number(cfg, int(time.time()))
|
||
if last_seq.get(name) == seq:
|
||
continue # этого такта ещё не было — ждём границу
|
||
last_seq[name] = seq
|
||
if cfg.uses_llm and _runners.get(name, {}).get("busy"):
|
||
# уровень ещё работает в предыдущем такте — тик поглощается,
|
||
# но остальные уровни продолжают жить
|
||
continue
|
||
t = threads.get(name)
|
||
if t is not None and t.is_alive():
|
||
continue
|
||
def _run(cfg=cfg, seq=seq):
|
||
model = es.run_projections()
|
||
state = process_level(cfg, model)
|
||
if state not in ("already",):
|
||
_log(f"{cfg.name} #{seq}: {state}")
|
||
t = threading.Thread(target=_run, daemon=True, name=f"tick-{name}")
|
||
threads[name] = t
|
||
t.start()
|
||
time.sleep(POLL)
|
||
|
||
|
||
if __name__ == "__main__":
|
||
main_loop() |