Files
Conflict_Checker/backend/jobs.py
T
woogi 7488cf68c5
Docker Release / build-and-push (push) Successful in 1m13s
Docker Release / release (push) Skipped
Verbose per-call LLM logging, raw request/response dumps, and end-of-log cost summary.
- [LLM] line per call: stage, model, prompt size, output size, cost, parsed item counts
- LLM_RAW_DUMP: full prompt/response JSON per call under outputs/<job>/llm_raw/
- Cost block at tail of job.log (per-stage, per-model, cached vs live)
- Agent mode: reset llm cost counters per job; review finalization now teed into job.log + dumps
2026-08-05 15:17:17 -05:00

408 lines
17 KiB
Python

"""
jobs.py - Lightweight async job registry for conflict checks.
A conflict check takes minutes, so the HTTP request must not block on it. Each
upload becomes a job that runs on a background thread; the client gets a job_id
immediately and can either poll GET /jobs/{id} or just close the page and wait
for the completion email.
State is in-memory (fine for a single-user tool); the report is also persisted
to outputs/<job_id>/ so results survive a restart even though live status does
not. No external queue/DB.
A teed stdout/stderr log is kept in memory and written to outputs/<job_id>/job.log
so failed or suspicious runs can be reviewed after the fact.
"""
import json
import os
import time
import traceback
import uuid
import shutil
import threading
from contextlib import contextmanager
from typing import Dict, Iterator, List, Optional
from backend import config
from backend import llm
from backend.job_log import capture_stdio, read_log_file, stamp_line
from backend.agents.runner import run_agent_pipeline
from backend.pipeline.runner import run_pipeline
from backend.email_sender import send_conflict_report, send_review_required
_jobs: Dict[str, Dict] = {}
_lock = threading.Lock()
_LOG_TAIL = 80
PIPELINE_MODES = {"classic", "agent"}
# States where the job will produce no more log output; polls get the full log.
_TERMINAL_STATES = {"done", "error", "needs_review", "finalization_error"}
def _set(job_id: str, **fields) -> None:
with _lock:
_jobs[job_id].update(fields)
def _append_log(job_id: str, raw_line: str, log_path: str) -> None:
"""Stamp, store, and append one captured stdout/stderr line."""
entry = stamp_line(raw_line)
with _lock:
job = _jobs.get(job_id)
if job is not None:
job.setdefault("log", []).append(entry)
try:
os.makedirs(os.path.dirname(log_path), exist_ok=True)
with open(log_path, "a", encoding="utf-8") as f:
f.write(entry + "\n")
except OSError:
# Don't fail the job over log I/O; avoid print() here — it would
# re-enter the stdio tee while a job is capturing.
pass
def create_job(
pdf_path: str,
source_filename: str,
email: Optional[str] = None,
project_input: Optional[Dict] = None,
text_local: bool = False,
pipeline_mode: str = "classic",
vision_model: Optional[str] = None,
text_model: Optional[str] = None,
) -> str:
"""Register a job and kick off its background thread. Returns the job_id."""
pipeline_mode = pipeline_mode.strip().lower()
if pipeline_mode not in PIPELINE_MODES:
raise ValueError(f"Unsupported pipeline mode: {pipeline_mode!r}")
# Agent mode v1 is OpenRouter-only.
text_local = bool(text_local and pipeline_mode == "classic")
job_id = uuid.uuid4().hex[:12]
with _lock:
_jobs[job_id] = {
"job_id": job_id,
"status": "queued", # queued -> running -> done | needs_review | error
"source": source_filename,
"email": email or None,
"project_input": project_input or {},
"text_local": text_local,
"pipeline_mode": pipeline_mode,
"vision_model": (vision_model or "").strip() or None,
"text_model": (text_model or "").strip() or None,
"stage": None,
"created_at": time.time(),
"finished_at": None,
"report": None,
"error": None,
"log": [],
}
threading.Thread(
target=_run,
args=(job_id, pdf_path, project_input, text_local, pipeline_mode,
vision_model, text_model),
daemon=True,
).start()
return job_id
def _run(
job_id: str,
pdf_path: str,
project_input: Optional[Dict] = None,
text_local: bool = False,
pipeline_mode: str = "classic",
vision_model: Optional[str] = None,
text_model: Optional[str] = None,
) -> None:
out_dir = os.path.join(config.OUTPUT_DIR, job_id)
log_path = os.path.join(out_dir, "job.log")
try:
_set(job_id, status="running")
os.makedirs(out_dir, exist_ok=True)
# Truncate any leftover log if job_id somehow collided (shouldn't).
with open(log_path, "w", encoding="utf-8"):
pass
header = (f"=== Job {job_id} | {pipeline_mode} | {_jobs[job_id].get('source')} | "
f"vision={vision_model or 'default'} text={text_model or 'default'} | "
f"started {time.strftime('%Y-%m-%d %H:%M:%S %Z', time.gmtime())} UTC ===")
_append_log(job_id, header, log_path)
def on_line(raw: str) -> None:
_append_log(job_id, raw, log_path)
with capture_stdio(on_line):
_run_pipeline(job_id, pdf_path, out_dir, project_input, text_local,
pipeline_mode, vision_model, text_model)
except Exception as e:
# Land the failure AND its traceback in the job log so failed runs can
# be diagnosed from the log alone (the stdio tee is already torn down).
try:
_append_log(job_id, f"[Jobs] Job {job_id} failed: {e}", log_path)
for ln in traceback.format_exc().rstrip().splitlines():
_append_log(job_id, ln, log_path)
# Cost-so-far for the failed run (counters are reset per job).
cost = llm.get_cost()
_append_log(job_id,
f"[Jobs] Estimated LLM cost before failure: "
f"${cost['usd']:.4f} over {cost['calls']} live calls "
f"({cost.get('cached', 0)} cached)", log_path)
except Exception:
pass
print(f"[Jobs] Job {job_id} failed: {e}")
_set(job_id, status="error", error=str(e), finished_at=time.time())
_notify_error(job_id)
finally:
try:
os.remove(pdf_path)
except OSError:
pass
def _run_pipeline(job_id: str, pdf_path: str, out_dir: str,
project_input: Optional[Dict], text_local: bool,
pipeline_mode: str, vision_model: Optional[str],
text_model: Optional[str]) -> None:
"""The body of a job run; executes inside the job's tee'd log capture."""
# Persist minimal job metadata so the disk fallback in get_job can
# recover the recipient email / pipeline mode after a server restart
# (plain json.dump, matching the _dump style used elsewhere).
with open(os.path.join(out_dir, "job.json"), "w", encoding="utf-8") as f:
json.dump({
"job_id": job_id,
"email": _jobs[job_id].get("email"),
"pipeline_mode": pipeline_mode,
"source": _jobs[job_id].get("source"),
"vision_model": vision_model,
"text_model": text_model,
}, f, indent=2)
# Keep a copy of the source PDF so its sheets can be viewed later.
shutil.copy2(pdf_path, os.path.join(out_dir, "source.pdf"))
# Raw per-call LLM request/response dumps land in <out_dir>/llm_raw/.
if config.LLM_RAW_DUMP:
llm.set_raw_dump_dir(os.path.join(out_dir, "llm_raw"))
runner = run_agent_pipeline if pipeline_mode == "agent" else run_pipeline
runner_kwargs = {
"out_dir": out_dir,
"on_stage": lambda name: _set(job_id, stage=name),
"project_input": project_input,
"source_name": _jobs[job_id].get("source"),
}
if pipeline_mode == "classic":
# run_pipeline takes the picks as params and clears them in finally.
runner_kwargs["text_local"] = text_local
runner_kwargs["vision_model"] = vision_model
runner_kwargs["text_model"] = text_model
else:
runner_kwargs["require_review"] = config.AGENT_REQUIRE_REVIEW
# The agent runner has no override params; set them module-level.
if vision_model or text_model:
print(f"[Jobs] Model overrides for this run: "
f"vision={vision_model or '(default)'} text={text_model or '(default)'}")
llm.set_model_overrides(vision_model, text_model)
try:
report = runner(pdf_path, **runner_kwargs)
finally:
llm.set_raw_dump_dir(None)
if pipeline_mode == "agent":
llm.set_model_overrides(None, None)
report.setdefault("summary", {})["pipeline_mode"] = pipeline_mode
_log_cost_summary(report.get("summary", {}))
if report["summary"].get("agent_status") == "needs_review":
# Human-review gate: hold the job, don't email the unreviewed report.
_set(job_id, status="needs_review", report=report,
finished_at=time.time(), stage=None)
email = _jobs[job_id].get("email")
if email:
review_url = f"{config.APP_BASE_URL.rstrip('/')}/?job={job_id}"
send_review_required(email, report, review_url)
else:
_set(job_id, status="done", report=report, finished_at=time.time(), stage=None)
_notify(job_id, report, out_dir)
def _log_cost_summary(summary: Dict, label: str = "this run") -> None:
"""
End-of-log estimated LLM cost block, printed inside the job's stdio tee so
it lands at the tail of job.log. Both runners populate the same summary
fields (cost_usd / llm_calls / cached_calls / cost_by_stage / models_used).
Hybrid note: local text calls carry no usage accounting, so the dollar
figure covers OpenRouter calls only (local call counts still appear).
"""
if summary.get("cost_usd") is None and not summary.get("llm_calls"):
return
print(f"\n=== Estimated LLM cost ({label}) ===")
print(f" Total: ${summary.get('cost_usd', 0.0):.4f} across "
f"{summary.get('llm_calls', 0)} live calls "
f"({summary.get('cached_calls', 0)} cached at $0)")
for name, bucket in (summary.get("cost_by_stage") or {}).items():
print(f" {name}: ${bucket.get('usd', 0.0):.4f} "
f"({bucket.get('calls', 0)} live, {bucket.get('cached', 0)} cached)")
mu = summary.get("models_used") or {}
if mu.get("vision"):
print(f" Vision models: {', '.join(mu['vision'])}")
if mu.get("text_local"):
print(f" Text models (local): {', '.join(mu['text_local'])}")
if mu.get("text_cloud"):
print(f" Text models (cloud): {', '.join(mu['text_cloud'])}")
if mu.get("fallback_count"):
print(f" Local->cloud fallbacks: {mu['fallback_count']}")
if mu.get("text_local"):
print(" Note: local calls have no cost accounting; "
"the dollar total covers OpenRouter usage only.")
@contextmanager
def capture_job_output(job_id: str, out_dir: str) -> Iterator[None]:
"""
Re-open the stdio tee + raw LLM dump dir for post-run work that still
belongs to this job (review finalization): lines append to job.log and
the in-memory log, raw dumps resume under <out_dir>/llm_raw/. The tee is
process-global — same overlapping-job caveat as the main run.
"""
log_path = os.path.join(out_dir, "job.log")
if config.LLM_RAW_DUMP:
llm.set_raw_dump_dir(os.path.join(out_dir, "llm_raw"))
try:
with capture_stdio(lambda raw: _append_log(job_id, raw, log_path)):
yield
finally:
llm.set_raw_dump_dir(None)
def _notify(job_id: str, report: Dict, out_dir: str) -> None:
email = _jobs[job_id].get("email")
if not email:
return
results_url = f"{config.APP_BASE_URL.rstrip('/')}/?job={job_id}"
attachments = [
os.path.join(out_dir, "report.md"),
os.path.join(out_dir, "conflicts.json"),
os.path.join(out_dir, "validated_issues.json"),
os.path.join(out_dir, "rfis.json"),
]
send_conflict_report(email, report, results_url=results_url, attachments=attachments)
def _notify_error(job_id: str) -> None:
job = _jobs[job_id]
email = job.get("email")
if not email:
return
try:
from backend.email_sender import _smtp_ready, _send
from email.message import EmailMessage
if not _smtp_ready():
print(f"[Email] SMTP not configured - skipping error notice to {email}")
return
msg = EmailMessage()
msg["Subject"] = f"Conflict Checker - {job.get('source','')} - run FAILED"
msg["From"] = config.SMTP_FROM or config.SMTP_USER
msg["To"] = email
msg.set_content(
"Your conflict check did not complete.\n\n"
f"Drawing set: {job.get('source','')}\n"
f"Error: {job.get('error','unknown')}\n\n"
f"Review the run log at: {config.APP_BASE_URL.rstrip('/')}/?job={job_id}\n\n"
"Generated by Conflict Checker"
)
_send(msg)
except Exception as e:
print(f"[Email] Failed to send error notice: {e}")
def _log_from_disk(job_id: str) -> List[str]:
return read_log_file(os.path.join(config.OUTPUT_DIR, job_id, "job.log"))
def get_job_log(job_id: str) -> Optional[List[str]]:
"""Full job log lines, from memory or disk. None if job unknown."""
with _lock:
job = _jobs.get(job_id)
if job is not None:
return list(job.get("log") or [])
log = _log_from_disk(job_id)
# Job exists on disk if we have a log or a report artifact.
report_path = os.path.join(config.OUTPUT_DIR, job_id, "conflicts.json")
if log or os.path.isfile(report_path):
return log
return None
def get_job(job_id: str) -> Optional[Dict]:
"""Public job view. Includes the full report only when done.
Falls back to the on-disk artifacts (conflicts.json / job.log) when the
job isn't in the in-memory registry (e.g. after a server restart).
"""
with _lock:
job = _jobs.get(job_id)
if job:
out = dict(job)
log = list(job.get("log") or [])
out["log_tail"] = log[-_LOG_TAIL:]
# Full log on terminal states so the UI can show it without a
# second fetch; keep polls light while running.
if out.get("status") in _TERMINAL_STATES:
out["log"] = log
else:
out.pop("log", None)
return out
# Try loading from disk
report_path = os.path.join(config.OUTPUT_DIR, job_id, "conflicts.json")
log = _log_from_disk(job_id)
if not os.path.isfile(report_path) and not log:
return None
try:
report = None
if os.path.isfile(report_path):
with open(report_path, encoding="utf-8") as f:
report = json.load(f)
summary = (report or {}).get("summary", {})
if report is None:
# Crashed before writing a report; the log is the only artifact.
status = "error"
else:
# Recover the job's real state: a job that stopped at the review gate
# must come back as needs_review (not done) or it can never finalize.
status = "needs_review" if summary.get("agent_status") == "needs_review" else "done"
# job.json (written at job start) carries the recipient email and
# pipeline mode so the final notification still fires after a restart.
# Missing/corrupt job.json degrades to the previous derivations.
meta: Dict = {}
meta_path = os.path.join(config.OUTPUT_DIR, job_id, "job.json")
try:
with open(meta_path, encoding="utf-8") as f:
loaded = json.load(f)
if isinstance(loaded, dict):
meta = loaded
except (OSError, json.JSONDecodeError):
pass
source_pdf = os.path.join(config.OUTPUT_DIR, job_id, "source.pdf")
job = {
"job_id": job_id,
"status": status,
"source": meta.get("source") or (report or {}).get("source", os.path.basename(report_path)),
"email": meta.get("email"),
"project_input": (report or {}).get("project_input", {}),
"text_local": summary.get("text_backend") == "local",
"pipeline_mode": meta.get("pipeline_mode") or summary.get("pipeline_mode", "classic"),
"vision_model": meta.get("vision_model"),
"text_model": meta.get("text_model"),
"stage": None,
"created_at": os.path.getmtime(source_pdf) if os.path.isfile(source_pdf) else None,
"finished_at": os.path.getmtime(report_path) if os.path.isfile(report_path) else None,
"report": report,
"error": None if report is not None else "Report missing; see job log",
"log": log,
"log_tail": log[-_LOG_TAIL:],
}
# Hydrate the in-memory registry so _set(...) transitions (reviewing,
# finalizing, done) work for restart-recovered jobs.
with _lock:
return dict(_jobs.setdefault(job_id, job))
except Exception as e:
print(f"[Jobs] Failed to load job {job_id} from disk: {e}")
return None