Skip to content

Commit a5e529e

Browse files
hycomplclaude
hycompl
and
claude
committed
Non-blocking runs + observability (fix "Start hangs" / "reject does nothing")
Run-launch endpoints blocked the HTTP request while the engine drove the whole pipeline synchronously — with the real claude backend a node takes minutes, so the cockpit's "Starting…"/decision buttons hung with no feedback and no logs. - engine: split launch from drive — `create()` seeds the run (row + RUNNING + initial state + run.start) and returns the run_id fast; `drive_existing()` loads state and `_drive`s. `start()`/`resume()` unchanged (CLI/tests). - moira_api: `background()` runs the drive off the request thread with its OWN Store + Engine (SQLite is per-thread). `/api/runs`, `/api/discovery`, gate approve/reject now return `{run_id, status:"running"}` immediately; the cockpit streams progress. `/api/eval` stays synchronous (returns the scorecard). - store: WAL + busy_timeout so the request read and the background write don't hit "database is locked". - logging: sidecar logs to a file (MOIRA_LOG, default next to MOIRA_DB) + stdout; run launches / gate decisions / background errors logged. GET /api/logs?tail=N; log path in /api/health. - cockpit: InboxPage decide() now try/catch/finally, always refreshes, and shows a notice (fixes "reject does nothing" — it re-runs and re-escalates, now visible and errors surfaced). Activity page gains a "Sidecar logs" tab. Discovery start messages reflect the running (non-blocking) state. Verified: POST /api/runs returns in ~50ms (status running) and the run completes in the background; /api/logs tails the logfile. 103 tests green, cockpit build clean. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
1 parent d07aa0c commit a5e529e

8 files changed

Lines changed: 168 additions & 41 deletions

File tree

‎CONTRIBUTING.md‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -89,6 +89,26 @@ Windows installers are currently unsigned (SmartScreen will warn) — add a code
8989
**Cut a release:** bump `version` in `src-tauri/tauri.conf.json` (and optionally `cockpit/package.json`),
9090
commit, then `git tag vX.Y.Z && git push origin vX.Y.Z`. Watch the **Actions** tab.
9191

92+
## Debugging / logs
93+
94+
Runs launch **non-blocking**: `POST /api/runs`, `/api/discovery`, and gate approve/reject return a
95+
`run_id` immediately and drive the pipeline on a background thread — the cockpit then streams progress
96+
(Runs/Inbox poll every ~2.5 s). So a real `claude` step no longer freezes the "Start"/decision button.
97+
98+
Where to look when something misbehaves:
99+
- **Live, per run:** open **Runs**, select the run → execution plan (per-node status) + a streaming
100+
activity log. Node failures show as `retry` / `node.escalate` events carrying the error (e.g. `claude`
101+
stderr or timeout).
102+
- **Across runs:** the **Activity** page → **Events** tab (all runs) and **Sidecar logs** tab (the
103+
orchestrator logfile, tailed live).
104+
- **Logfile on disk:** `MOIRA_LOG` (default next to `MOIRA_DB` → `<app-data>/moira.log` in the desktop
105+
app; the path is also in `GET /api/health` and `GET /api/logs?tail=N`).
106+
- **Dev:** run `./run-cockpit.sh` (or `python3 orchestrator/moira_api.py …`) in a terminal — the sidecar
107+
logs to stdout there too. For the UI, use the Tauri webview devtools.
108+
109+
Note: `POST /api/eval` (quality/conformance/compliance scorecards) is intentionally **synchronous** — it
110+
returns the scorecard in the response, so that call does block until the judge finishes.
111+
92112
## Conventions
93113

94114
- Keep the orchestrator **dependency-free** (stdlib only) — it ships as the sidecar.

‎cockpit/src/api.ts‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -217,6 +217,8 @@ export const api = {
217217
POST("/api/eval", { owner: _user.name, kind: "compliance", references, ...opts, workspace_id: activeWs }),
218218
regulations: (): Promise<{ regulations: Regulation[] }> => fetch(ws("/api/regulations")).then(j),
219219
spend: (): Promise<SpendRollup> => fetch(ws("/api/spend")).then(j),
220+
logs: (tail = 400): Promise<{ path: string | null; log: string }> =>
221+
fetch(u(`/api/logs?tail=${tail}`)).then(j),
220222
};
221223

222224
// per-workspace monthly budget (alert-only v1; kept client-side like the profile)

‎cockpit/src/pages/ActivityPage.tsx‎

Lines changed: 34 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -2,27 +2,47 @@ import { useEffect, useState } from "react";
22
import { api, type ActivityRow } from "../api";
33

44
export function ActivityPage() {
5+
const [tab, setTab] = useState<"events" | "logs">("events");
56
const [rows, setRows] = useState<ActivityRow[]>([]);
7+
const [logText, setLogText] = useState("");
8+
const [logPath, setLogPath] = useState<string | null>(null);
9+
610
useEffect(() => {
7-
const load = () => api.activity().then((d) => setRows(d.activity)).catch(() => { /* */ });
11+
if (tab === "events") {
12+
const load = () => api.activity().then((d) => setRows(d.activity)).catch(() => { /* */ });
13+
load(); const t = setInterval(load, 3000); return () => clearInterval(t);
14+
}
15+
const load = () => api.logs().then((d) => { setLogText(d.log); setLogPath(d.path); }).catch(() => { /* */ });
816
load(); const t = setInterval(load, 3000); return () => clearInterval(t);
9-
}, []);
17+
}, [tab]);
1018

1119
return (
1220
<div className="page">
13-
<h2>Activity <span className="muted">· recent events across all runs</span></h2>
14-
<div className="panel grow">
15-
<div className="log">
16-
{rows.map((e) => (
17-
<div className={"log-row k-" + e.kind.split(".")[0]} key={`${e.run_id}-${e.seq}`}>
18-
<span className="kind">{e.kind}</span>
19-
<span className="run-ref">{e.run_id.replace("run-", "")}</span>
20-
<span className="lmsg">{e.message}</span>
21-
</div>
22-
))}
23-
{rows.length === 0 && <div className="empty">No activity yet.</div>}
24-
</div>
21+
<h2>Activity <span className="muted">· what the orchestrator is doing</span></h2>
22+
<div className="toolbar" style={{ gap: 6 }}>
23+
<button className={"seg-btn" + (tab === "events" ? " on" : "")} onClick={() => setTab("events")}>Events</button>
24+
<button className={"seg-btn" + (tab === "logs" ? " on" : "")} onClick={() => setTab("logs")}>Sidecar logs</button>
25+
{tab === "logs" && logPath && <span className="muted small" style={{ marginLeft: "auto" }}>{logPath}</span>}
2526
</div>
27+
28+
{tab === "events" ? (
29+
<div className="panel grow">
30+
<div className="log">
31+
{rows.map((e) => (
32+
<div className={"log-row k-" + e.kind.split(".")[0]} key={`${e.run_id}-${e.seq}`}>
33+
<span className="kind">{e.kind}</span>
34+
<span className="run-ref">{e.run_id.replace("run-", "")}</span>
35+
<span className="lmsg">{e.message}</span>
36+
</div>
37+
))}
38+
{rows.length === 0 && <div className="empty">No activity yet.</div>}
39+
</div>
40+
</div>
41+
) : (
42+
<div className="panel grow">
43+
<pre className="log" style={{ whiteSpace: "pre-wrap", margin: 0 }}>{logText || "No logs yet."}</pre>
44+
</div>
45+
)}
2646
</div>
2747
);
2848
}

‎cockpit/src/pages/InboxPage.tsx‎

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ function DecisionCard({ it, codePath, onDecided }: {
2828
const [det, setDet] = useState<RunDetail | null | undefined>(undefined);
2929
const [note, setNote] = useState("");
3030
const [busy, setBusy] = useState(false);
31+
const [msg, setMsg] = useState("");
3132
const [artifact, setArtifact] = useState<Artifact | null>(null);
3233

3334
useEffect(() => { api.run(it.run_id).then(setDet).catch(() => setDet(null)); }, [it.run_id]);
@@ -51,12 +52,17 @@ function DecisionCard({ it, codePath, onDecided }: {
5152
}, [det, audit]);
5253

5354
const decide = async (kind: "approve" | "reject") => {
54-
setBusy(true);
55+
setBusy(true); setMsg("");
5556
try {
5657
if (kind === "approve") await api.approve(it.run_id, approver(), note || "Reviewed and accepted");
57-
else await api.reject(it.run_id, approver(), note);
58-
} finally { setBusy(false); }
59-
onDecided();
58+
else await api.reject(it.run_id, approver(), note || "Sent back for rework");
59+
setMsg(kind === "approve" ? "✓ Approved — continuing the run…" : "↩ Sent back for rework — re-running the step…");
60+
onDecided();
61+
} catch (e) {
62+
setMsg("⚠ Action failed: " + String((e as Error)?.message || e));
63+
} finally {
64+
setBusy(false);
65+
}
6066
};
6167

6268
return (
@@ -136,9 +142,10 @@ function DecisionCard({ it, codePath, onDecided }: {
136142
<div className="review-label" style={{ marginTop: 14 }}>Decision note <span className="muted">(recorded in the audit)</span></div>
137143
<textarea className="gate-note" placeholder={isClient ? "What you approve / what to change…" : "What did you verify? / feedback for rework…"}
138144
value={note} onChange={(e) => setNote(e.target.value)} />
145+
{msg && <div className={"dc-banner " + (msg.startsWith("⚠") ? "warn" : "ok")} style={{ marginTop: 10 }}>{msg}</div>}
139146
<div className="dc-actions">
140-
<Button variant="success" disabled={busy} onClick={() => decide("approve")}>✓ Approve</Button>
141-
<Button variant="danger" disabled={busy} onClick={() => decide("reject")}>↩ Reject &amp; rework</Button>
147+
<Button variant="success" disabled={busy} onClick={() => decide("approve")}>{busy ? "…" : "✓ Approve"}</Button>
148+
<Button variant="danger" disabled={busy} onClick={() => decide("reject")}>{busy ? "…" : "↩ Reject & rework"}</Button>
142149
</div>
143150
{artifact && <ArtifactModal artifact={artifact} onClose={() => setArtifact(null)} onOpen={viewArtifact} />}
144151
</div>

‎cockpit/src/pages/SkillsPage.tsx‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ export function SkillsPage() {
6464
if (!run) return; setBusy(true); setMsg("");
6565
try {
6666
const res = await api.runDiscovery({ skill: run.name, input, elaboration: elab, persona });
67-
setMsg(`Started ${res.run_id.replace("run-", "")} (${res.status}) — review in the Inbox.`);
67+
setMsg(`Started ${res.run_id.replace("run-", "")} — running. Watch it in Runs/Activity; the review gate appears in the Inbox when ready.`);
6868
setRun(null); setInput(""); setElab("");
6969
} catch (e) { setMsg(String((e as Error)?.message || e)); }
7070
setBusy(false);
@@ -77,7 +77,7 @@ export function SkillsPage() {
7777
// only the first step gets the topic; later steps inherit the prior step's artifact id
7878
const steps = pSteps.map((s, i) => ({ skill: s.skill, input: i === 0 ? pTopic : "", elaboration: pElab, persona: s.persona }));
7979
const res = await api.runDiscoveryPipeline(steps, pipe.name);
80-
setMsg(`Started pipeline ${res.run_id.replace("run-", "")} (${res.status}) — first gate is in the Inbox.`);
80+
setMsg(`Started pipeline ${res.run_id.replace("run-", "")} — running. Watch it in Runs/Activity; the first gate appears in the Inbox when ready.`);
8181
setPipe(null);
8282
} catch (e) { setMsg(String((e as Error)?.message || e)); }
8383
setBusy(false);

‎orchestrator/moira_api.py‎

Lines changed: 71 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -18,8 +18,11 @@
1818

1919
import argparse
2020
import json
21+
import logging
2122
import os
2223
import sys
24+
import threading
25+
import traceback
2326
from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
2427
from pathlib import Path
2528
from urllib.parse import parse_qs, urlparse
@@ -37,6 +40,46 @@
3740
DB = os.environ.get("MOIRA_DB", ".moira/moira.sqlite")
3841
REPO = None
3942
STATIC = None
43+
LOG_PATH = None
44+
log = logging.getLogger("moira")
45+
46+
47+
def setup_logging() -> None:
48+
"""Log to a file (MOIRA_LOG, default next to the DB) AND stdout, so the desktop
49+
app has a logfile and `run-cockpit.sh` shows live events in the terminal."""
50+
global LOG_PATH
51+
LOG_PATH = os.environ.get("MOIRA_LOG") or str(Path(DB).resolve().parent / "moira.log")
52+
fmt = logging.Formatter("%(asctime)s %(levelname)s %(message)s")
53+
log.setLevel(logging.INFO)
54+
log.handlers.clear()
55+
try:
56+
Path(LOG_PATH).parent.mkdir(parents=True, exist_ok=True)
57+
fh = logging.FileHandler(LOG_PATH)
58+
fh.setFormatter(fmt)
59+
log.addHandler(fh)
60+
except OSError:
61+
LOG_PATH = None
62+
sh = logging.StreamHandler()
63+
sh.setFormatter(fmt)
64+
log.addHandler(sh)
65+
66+
67+
def background(owner: str, fn) -> None:
68+
"""Drive a run OFF the request thread so the HTTP call returns immediately
69+
(the cockpit then polls). The thread uses its OWN Store + Engine (SQLite is
70+
per-thread). Exceptions are logged, never crash the server."""
71+
def _run():
72+
store = open_store()
73+
try:
74+
res = fn(Engine(store, registry(), owner=owner))
75+
rid = getattr(res, "run_id", "?")
76+
status = getattr(getattr(res, "status", None), "value", res)
77+
log.info("run %s -> %s", rid, status)
78+
except Exception: # noqa: BLE001
79+
log.error("background run failed:\n%s", traceback.format_exc())
80+
finally:
81+
store.close()
82+
threading.Thread(target=_run, daemon=True).start()
4083

4184

4285
def open_store():
@@ -407,8 +450,18 @@ def do_GET(self):
407450
git_on = os.environ.get("MOIRA_GIT_EXPORT", "0") not in ("", "0", "false", "False")
408451
persistence = primary + (" + git" if git_on else "")
409452
return self._send(200, {"ok": True, "backends": registry().available(),
410-
"repo": REPO, "persistence": persistence,
453+
"repo": REPO, "persistence": persistence, "log": LOG_PATH,
411454
"claude": ClaudeCodeBackend().available(), "version": "0.1"})
455+
if path == "/api/logs":
456+
n = int((parse_qs(parsed.query).get("tail", ["200"])[0]) or 200)
457+
text = ""
458+
try:
459+
if LOG_PATH and os.path.exists(LOG_PATH):
460+
with open(LOG_PATH, "r", encoding="utf-8", errors="replace") as f:
461+
text = "".join(f.readlines()[-n:])
462+
except OSError:
463+
pass
464+
return self._send(200, {"path": LOG_PATH, "log": text})
412465
if path == "/api/workspaces":
413466
return self._send(200, {"workspaces": store.list_workspaces()})
414467
if path == "/api/runs":
@@ -618,10 +671,11 @@ def do_POST(self):
618671
code = ws_code_path(store, ws_id) # real coding: agents write here (cwd)
619672
if code:
620673
ctx["cwd"] = code
621-
engine = Engine(store, registry(), owner=owner)
622-
res = engine.start(pipe, ctx, workspace_id=ws_id)
623-
return self._send(201, {"run_id": res.run_id, "status": res.status.value,
624-
"waiting_node": res.waiting_node})
674+
run_id = Engine(store, registry(), owner=owner).create(pipe, ctx, workspace_id=ws_id)
675+
log.info("launch run %s func=%s pipeline=%s backend=%s owner=%s",
676+
run_id, func_id, pipe.id, body.get("backend", "mock"), owner)
677+
background(owner, lambda e, p=pipe, c=ctx, r=run_id: e.drive_existing(r, p, c))
678+
return self._send(201, {"run_id": run_id, "status": "running", "waiting_node": None})
625679
if path.startswith("/api/runs/") and path.endswith("/report"):
626680
from moira_core.report import render_run_report
627681
from moira_core.git_sink import GitExportSink
@@ -736,17 +790,17 @@ def do_POST(self):
736790
pipe = Pipeline(id=pid, name=name, nodes=nodes)
737791
ctx = context_for(steps[0].get("input", ""), ws_repo(store, ws_id))
738792
ctx["cwd"] = ws_repo(store, ws_id) # author INTO the AI SDLC repo, not code
739-
engine = Engine(store, registry(), owner=owner)
740-
res = engine.start(pipe, ctx, workspace_id=ws_id)
741-
return self._send(201, {"run_id": res.run_id, "status": res.status.value,
742-
"waiting_node": res.waiting_node})
793+
run_id = Engine(store, registry(), owner=owner).create(pipe, ctx, workspace_id=ws_id)
794+
log.info("launch discovery %s steps=%s owner=%s",
795+
run_id, [s["skill"] for s in steps], owner)
796+
background(owner, lambda e, p=pipe, c=ctx, r=run_id: e.drive_existing(r, p, c))
797+
return self._send(201, {"run_id": run_id, "status": "running", "waiting_node": None})
743798
if path.endswith("/approve") or path.endswith("/reject"):
744799
run_id = path.split("/api/runs/", 1)[1].rsplit("/", 1)[0]
745800
run = store.get_run(run_id)
746801
if not run:
747802
return self._send(404, {"error": "not found"})
748803
pipe = Pipeline.from_dict(json.loads(run["pipeline"]))
749-
engine = Engine(store, registry(), owner=run["owner"])
750804
if path.endswith("/approve"):
751805
dec = GateDecision(decision="approve", by=body.get("by", "human"),
752806
confirmed=body.get("confirm", "approved via cockpit"))
@@ -763,9 +817,9 @@ def do_POST(self):
763817
code = ws_code_path(store, run_ws)
764818
if code:
765819
ctx["cwd"] = code
766-
res = engine.resume(run_id, pipe, ctx, dec)
767-
return self._send(200, {"run_id": res.run_id, "status": res.status.value,
768-
"waiting_node": res.waiting_node})
820+
log.info("gate %s %s by %s", run_id, dec.decision, dec.by)
821+
background(run["owner"], lambda e, p=pipe, c=ctx, d=dec, r=run_id: e.resume(r, p, c, d))
822+
return self._send(200, {"run_id": run_id, "status": "running", "waiting_node": None})
769823
if path == "/api/gate/simulate":
770824
cfg = GateConfig(mode=GateMode.HYBRID,
771825
high_cutoff=float(body.get("high_cutoff", 0.85)),
@@ -801,8 +855,11 @@ def main(argv=None) -> int:
801855
args = p.parse_args(argv)
802856
REPO = args.repo
803857
STATIC = args.static
858+
setup_logging()
804859
srv = ThreadingHTTPServer(("127.0.0.1", args.port), Handler)
805-
print(f"Moira API on http://127.0.0.1:{args.port} repo={REPO} static={STATIC}")
860+
log.info("Moira API on http://127.0.0.1:%s repo=%s static=%s log=%s",
861+
args.port, REPO, STATIC, LOG_PATH)
862+
print(f"Moira API on http://127.0.0.1:{args.port} repo={REPO} static={STATIC} log={LOG_PATH}")
806863
try:
807864
srv.serve_forever()
808865
except KeyboardInterrupt:

‎orchestrator/moira_core/engine.py‎

Lines changed: 18 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -57,16 +57,30 @@ def __init__(self, store: RunStore, registry: BackendRegistry, owner: str = "unk
5757
self.owner = owner
5858

5959
# ---- public API -------------------------------------------------------- #
60-
def start(self, pipeline: Pipeline, context: dict[str, Any],
61-
workspace_id: str = "default") -> RunResult:
60+
def create(self, pipeline: Pipeline, context: dict[str, Any],
61+
workspace_id: str = "default") -> str:
62+
"""Seed a run (row + RUNNING + initial state + run.start event) WITHOUT driving.
63+
Fast + synchronous — lets a caller return the run_id immediately and drive the
64+
slow agent work off-thread via `drive_existing` (see moira_api.background())."""
6265
run_id = new_id("run-")
6366
self.store.create_run(run_id, pipeline.id, pipeline.to_dict(),
6467
self.owner, Status.RUNNING.value, workspace_id=workspace_id)
6568
self._event(run_id, "run.start", f"Run started: pipeline '{pipeline.name}' by {self.owner}")
66-
state = {n.id: PENDING for n in pipeline.nodes}
67-
self.store.save_run_state(run_id, state)
69+
self.store.save_run_state(run_id, {n.id: PENDING for n in pipeline.nodes})
70+
return run_id
71+
72+
def drive_existing(self, run_id: str, pipeline: Pipeline,
73+
context: dict[str, Any]) -> RunResult:
74+
"""Drive a previously-`create`d run from its persisted state (the slow part)."""
75+
state = self.store.get_run_state(run_id) or {n.id: PENDING for n in pipeline.nodes}
6876
return self._drive(run_id, pipeline, context, state)
6977

78+
def start(self, pipeline: Pipeline, context: dict[str, Any],
79+
workspace_id: str = "default") -> RunResult:
80+
"""Synchronous create + drive (CLI / tests / synchronous callers)."""
81+
run_id = self.create(pipeline, context, workspace_id)
82+
return self.drive_existing(run_id, pipeline, context)
83+
7084
def resume(self, run_id: str, pipeline: Pipeline, context: dict[str, Any],
7185
decision: GateDecision) -> RunResult:
7286
run = self.store.get_run(run_id)

‎orchestrator/moira_core/store.py‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -72,8 +72,15 @@ class Store:
7272
def __init__(self, db_path: str | Path = ".moira/moira.sqlite"):
7373
self.db_path = Path(db_path)
7474
self.db_path.parent.mkdir(parents=True, exist_ok=True)
75-
self.conn = sqlite3.connect(str(self.db_path))
75+
self.conn = sqlite3.connect(str(self.db_path), timeout=30)
7676
self.conn.row_factory = sqlite3.Row
77+
# WAL + a busy timeout so a request-thread read and a background drive-thread
78+
# write (non-blocking run launch) don't collide with "database is locked".
79+
try:
80+
self.conn.execute("PRAGMA journal_mode=WAL")
81+
self.conn.execute("PRAGMA busy_timeout=5000")
82+
except sqlite3.Error:
83+
pass
7784
self.conn.executescript(SCHEMA)
7885
self.conn.commit()
7986
self._seq = 0

0 commit comments

Comments
 (0)