refactor: improve progress detail handling and logging in orchestrator

- Shorten console output for long details in progress notifications.
- Introduce a new function to merge and truncate subprocess output for better clarity in logs.
- Update tests to cover new behavior for subprocess output handling.

Made-with: Cursor

Author: amit221

paperclip

@@ -0,0 +1 @@
+Subproject commit 14ffbe30a0969df009dd776c66e02f3ad7d926ef

skills/issue-fix-workflow.md

@@ -22,17 +22,11 @@ If no repo is given, assume the current workspace root or ask once for `owner/re
 
 ## Run status (supervising agents)
 
-Long Iynx runs (`python run.py`) stream work through Docker and Cursor. A supervising agent or host process should **not** assume instant completion.
+For the **full** host pipeline—**discovery**, Docker, all Cursor phases, PR creation—read **`skills/iynx-run-workflow.md`** in the Iynx repo. It is the single runbook for `python run.py`.
 
-**Cadence:** Use a **scheduler (or timer) that checks run status every 60 seconds** until the run finishes or the user stops it. Sixty seconds is the default interval unless the user specifies another.
+**Short reminder:** Long runs stream through Docker and Cursor; **do not** assume instant completion.
 
-**What to check**
-
-- **Progress file:** `.iynx-run-progress.jsonl` at the Iynx project root (or the path in `IYNX_PROGRESS_JSONL` if set). Each line is one JSON event: `phase`, `status`, `repo`, `issue`, `detail`, `exit_code`.
-- **Done:** The run is finished when you see `phase` `run_complete` (read `detail` for `pr_created` vs `no_pr`, and `exit_code`).
-- **Between polls:** You can still read the latest line or tail new lines since the last check; avoid tight loops.
-
-**Implementation note:** The host may later ship a built-in scheduler that performs this 60s poll; until then, follow the same cadence when implementing supervision yourself.
+**Cadence:** Poll **`.iynx-run-progress.jsonl`** at the Iynx project root about **every 60 seconds** until **`phase` `run_complete`** (see **`iynx-run-workflow.md`** for phases and exit codes).
 
 ## Quick Checklist
 

skills/iynx-run-workflow.md

@@ -0,0 +1,142 @@
+# Iynx run workflow
+
+How to **start** the full Iynx pipeline (actually execute `python run.py`), then **supervise** it and **explain** it in plain language (progress, watch commands, failures like **`no_pr`**).
+
+For **manual** contribution work (no orchestrator), use **`issue-fix-workflow.md`**. The orchestrator injects that file into the target repo; it does **not** inject this one.
+
+---
+
+## 1. When the user wants to *run* the workflow — execute it
+
+If they say **run Iynx**, **start the workflow**, **run discovery**, **run `python run.py`**, or equivalent, you must **run the process**, not only read `.iynx-run-progress.jsonl` or describe what would happen.
+
+1. **`cd`** to the **Iynx repo root** (directory that contains **`run.py`**, **`Dockerfile`**, **`skills/`**).
+2. **Check prerequisites** before starting:
+   - **`CURSOR_API_KEY`** set (in `.env` beside `run.py` or in the environment). Without it the host exits **1** immediately.
+   - **`GITHUB_TOKEN`** set for real discovery and PR work (strongly recommended).
+   - Docker daemon running; image **`iynx-agent:latest`** built (`docker build -t iynx-agent:latest .` from that root if missing).
+3. **Run** the entrypoint:
+   - Full pipeline **with discovery:** `python run.py`
+   - **One repo** (no discovery): `python run.py owner/repo` or `python run.py owner/repo 849`
+4. **Long runs:** This can take **tens of minutes to an hour+** (Docker + Cursor phases). If your environment allows **background** execution for long commands, start it in the **background** and tell the user it is running; otherwise run foreground and warn that the session will stay busy. **Do not** skip starting the workflow because it is slow—start it, then use §§3–6 to report status.
+5. After it starts, confirm in your reply: **what ran** (command + discovery vs explicit target), and **how to watch** (§4).
+
+You can also pass the same targets via **`IYNX_TARGET_REPO`** and optional **`IYNX_TARGET_ISSUE`** instead of argv. Default `python run.py` runs **discovery** (GitHub issue search → filters → **random** repo), then the Docker/Cursor/PR pipeline.
+
+---
+
+## 2. What actually runs (for the user-facing sentence)
+
+The Iynx agent workflow is **`python run.py`** from that root. Details and env setup: **README → Usage**.
+
+When you tell the user what ran, say it plainly—e.g. *“The Iynx agent workflow is `python run.py` (see README under Usage).”* Note **foreground** vs **background** if you know.
+
+---
+
+## 3. “Progress so far” — how to describe it
+
+Read **`.iynx-run-progress.jsonl`** at the **Iynx project root** (gitignored). Each line is one JSON object: `phase`, `status`, `repo`, `issue`, `detail`, `run_id`, `exit_code`, etc. Use **`IYNX_PROGRESS_JSONL`** only if the user overrode the path.
+
+Build the narrative in this order (skip lines the user’s run has not reached yet):
+
+1. **Discovery** (only when there was no explicit `owner/repo`): Find the row with `phase` **`discovery`**. If `status` is **`completed`**, `detail` is usually the **number of repos** after filters (string). Say e.g. *“Discovery: 29 repos after filters.”* If `status` is **`skipped`** and `detail` is **`no_repos`**, the run stopped early—**no clone**—and will hit **`run_complete`** with **`no_pr`**.
+2. **Selected repo:** The host logs something like *“Selected owner/repo (random of N qualifying)”*; the JSONL rows for **`clone`** onward carry **`repo`**: **`owner/repo`**. Say e.g. *“Selected repo: judgemind/judgemind (random pick).”*
+3. **Preflight:** Row **`preflight`**. **`completed`** → *“Preflight: passed (open issues exist)”* or, with an issue override, that the issue was validated. **`failed`** → read `detail` (e.g. no open issues, bad issue number) and say the run **did not clone**.
+4. **Clone:** **`clone`** **`completed`** → *“Clone: finished (repo cloned in Docker).”*
+5. **Bootstrap:** **`bootstrap`** **`completed`** → fold into *“Clone / bootstrap: done”* if you want a short status.
+6. **Cursor phases** — use **friendly names** in the user-facing summary; tie them to JSONL `phase` values:
+
+| Say this | JSONL `phase` |
+|----------|----------------|
+| Phase 1 (context) | `phase1_context` |
+| Phase 2 (issue pick) | `phase2_issue_pick` |
+| Phase 3 (implement) | `phase3_implement` |
+| Phase 4 (PR draft) | `phase4_pr_draft` |
+| PR create | `pr_create` |
+
+For each: **`started`** / **`completed`** / **`failed`**. If **`phase3_implement`** is **`started`** or only **`phase1`/`phase2`** are **`completed`**, say clearly what is **still in progress** (e.g. *“Phase 3 (implement) in progress — issue #1545”* when `issue` is present on the row).
+
+7. **Still running:** If there is **no** row with `phase` **`run_complete`** yet, the run is **not** finished. Mention that **phase4**, **pr_create**, and **run_complete** are still to come, or whichever is next.
+
+8. **Duration:** Long runs are normal. Per Docker step, the default timeout is **large** (on the order of **3600s** unless changed—see **`IYNX_DOCKER_RUN_TIMEOUT`** in §8).
+
+---
+
+## 4. “How to watch it” — tell the user
+
+- **Console:** Same session’s log stream; lines tagged **`[docker]`** and **`[iynx]`** mirror progress.
+- **Structured file:** Full path to **`.iynx-run-progress.jsonl`** (project root); each line is JSON; **final** lifecycle row is **`run_complete`** when the process is done.
+- **PowerShell:** `Get-Content .iynx-run-progress.jsonl -Wait`
+- **Unix:** `tail -f .iynx-run-progress.jsonl`
+
+Optional: mention **`run_id`** from a recent JSON line so multiple runs are distinguishable.
+
+---
+
+## 5. Status updates while running
+
+A **table** is easy to scan:
+
+| Step | Status |
+|------|--------|
+| Discovery | Done — N repos *(or skipped / not applicable if explicit target)* |
+| Preflight | Done — `owner/repo` |
+| Clone / bootstrap | Done |
+| Phase 1 (context) | Done |
+| Phase 2 (issue pick) | Done |
+| Phase 3 (implement) | In progress — issue #N *(or Done)* |
+
+If **`phase4_pr_draft`**, **`pr_create`**, or **`run_complete`** are **missing**, say the agent **has not** finished implementation or **opened a PR** yet.
+
+Mention **process** if known: e.g. still running, approximate elapsed time from logs.
+
+---
+
+## 6. When the run finishes
+
+Read the last **`run_complete`** row:
+
+- **`detail`:** **`pr_created`** vs **`no_pr`**
+- **`exit_code`:** aligns with the process (**0** = PR created, **2** = finished without PR, **1** = fatal host config such as missing **`CURSOR_API_KEY`**)
+
+**If the user sees exit 2 and `no_pr` but phases mostly succeeded**, do **not** stop at “no PR.” Scan JSONL (and stderr/log) for the **last failing step**, often **`pr_create`** with `status` **`failed`** and `exit_code` on that row.
+
+### Example: PR not created because of a label
+
+Orchestrator passes **`IYNX_PR_LABEL`** into `gh pr create`. If that label **does not exist** on the **upstream** repo, `gh` fails with something like *`could not add label: 'lynx' not found`*.
+
+**What to tell the user:**
+
+- What **succeeded** (e.g. repo, issue, phases through implement/draft, branch pushed to fork—if logs show that).
+- **Why no PR:** `pr_create` failed; quote or paraphrase the **`gh`** error.
+- **What they can do:** Create the label on the upstream repo (if they control it), **or** unset / change **`IYNX_PR_LABEL`** in `.env` and re-run, **or** open the PR manually from GitHub’s “compare / new PR” flow for the pushed branch.
+
+Always tie **actionable** steps to the **actual** error text you see.
+
+---
+
+## 7. Polling (supervising agents)
+
+Do **not** assume `python run.py` finishes quickly. If you are checking on a run, **poll** **`.iynx-run-progress.jsonl`** on the order of **every 60 seconds** (or as the user asks), reading **new** lines since the last check—not a tight loop.
+
+---
+
+## 8. Short reference (implementation details)
+
+Use this when you need exact behavior, not when writing a user-facing status blurb.
+
+**Discovery (default `python run.py`):** GitHub **issue search** per language (**JavaScript, TypeScript, Python**), pool capped by **`DISCOVERY_POOL_SIZE`** (see `src/orchestrator.py`). Filters: **CONTRIBUTING** expected; optionally **skip repos where the token’s user already has PRs**. One repo chosen with **`random.choice`**. Tuning is via **constants** in **`orchestrator.py`**, not env vars.
+
+**Explicit target:** **`IYNX_TARGET_REPO`** or `python run.py owner/repo [issue]` → **discovery skipped**; **`target_resolve`** in JSONL.
+
+**Pipeline order:** `preflight` → `clone` → `bootstrap` → `phase1_context` → `phase2_issue_pick` (skipped when issue fixed upfront) → `phase3_implement` → `verify_tests` (often **skipped**; **`VERIFY_TESTS_AFTER_FIX`** default **false** in code) → `phase4_pr_draft` → `pr_create` → **`run_complete`**.
+
+**Exit codes:** **0** = PR created; **1** = fatal host misconfiguration; **2** = ended without PR.
+
+**Env (common):** `CURSOR_API_KEY` (required), `GITHUB_TOKEN`, `IYNX_TARGET_REPO`, `IYNX_TARGET_ISSUE`, `IYNX_PROGRESS_JSONL`, `IYNX_DOCKER_RUN_TIMEOUT`, `IYNX_PR_LABEL`, `IYNX_DOCKER_TRACE`, `IYNX_CURSOR_MODEL`, … — full list in **`README`** / **`src/orchestrator.py`**.
+
+**Clones:** Under **`workspace/`** at the Iynx root.
+
+**Follow-up on an existing PR:** **`issue-fix-workflow.md`** (PR review section) and **`pr_review.py`**.
+
+**Source files:** `run.py`, `src/orchestrator.py`, `src/discovery.py`.

src/orchestrator.py

@@ -195,7 +195,12 @@ def _notify_progress(
     if issue is not None:
         parts.append(f"issue={issue}")
     if detail:
-        parts.append(detail)
+        # Full `detail` is stored in JSONL; keep console `[iynx]` lines short.
+        if len(detail) > 500:
+            one_line = detail[:500].replace("\n", " ").strip()
+            parts.append(f"{one_line} ... [detail {len(detail)} chars; see JSONL]")
+        else:
+            parts.append(detail)
     if exit_code is not None:
         parts.append(f"exit_code={exit_code}")
     logger.info("[iynx] %s", " ".join(parts))
@@ -210,6 +215,31 @@ def _notify_progress(
         )
 
 
+# Cap for progress JSONL `detail` on subprocess failures (e.g. gh pr create stderr).
+_PROGRESS_SUBPROCESS_DETAIL_MAX = 4000
+
+
+def _progress_detail_from_subprocess(
+    result: subprocess.CompletedProcess[str],
+    *,
+    max_chars: int | None = None,
+) -> str:
+    """Merge stderr/stdout from a failed CompletedProcess for progress JSONL."""
+    limit = max_chars if max_chars is not None else _PROGRESS_SUBPROCESS_DETAIL_MAX
+    err = (result.stderr or "").strip()
+    out = (result.stdout or "").strip()
+    if err and out and err not in out:
+        combined = f"{err}\n---\n{out}"
+    else:
+        combined = err or out
+    combined = combined.replace("\r\n", "\n").strip()
+    if not combined:
+        return "no_output"
+    if len(combined) <= limit:
+        return combined
+    return f"...(truncated, {len(combined)} chars total)\n" + combined[-limit:]
+
+
 def _parse_owner_repo_string(raw: str) -> tuple[str, str] | None:
     s = raw.strip().rstrip("/")
     if not s:
@@ -977,13 +1007,15 @@ def run_one_repo(
                 workdir="/home/dev/workspace",
             )
             if r5.returncode != 0:
-                logger.error("PR creation failed: %s", r5.stderr or r5.stdout)
+                pr_fail_detail = _progress_detail_from_subprocess(r5)
+                logger.error("PR creation failed: %s", pr_fail_detail)
                 _notify_progress(
                     progress,
                     repo.full_name,
                     "pr_create",
                     "failed",
                     issue=issue_num,
+                    detail=pr_fail_detail,
                     exit_code=r5.returncode,
                 )
                 return False

src/pr_stats.py

@@ -293,9 +293,7 @@ def compute_stats(
 
     max_fetchable = min(open_total, 1000) + min(closed_total, 1000)
     user_capped = (
-        max_items is not None
-        and fetched_total >= max_items
-        and fetched_total < max_fetchable
+        max_items is not None and fetched_total >= max_items and fetched_total < max_fetchable
     )
 
     kept: list[tuple[str, dict[str, Any]]] = []
@@ -601,8 +599,7 @@ def run(argv: list[str] | None = None) -> int:
     lim = result.limits
     if lim.get("search_truncated"):
         print(
-            "warning: GitHub Search returned more than 1,000 matches; "
-            "counts may omit older PRs.",
+            "warning: GitHub Search returned more than 1,000 matches; counts may omit older PRs.",
             file=sys.stderr,
         )
     if lim.get("user_capped"):

tests/test_orchestrator_unit.py

@@ -38,6 +38,29 @@ def test_read_json_file_os_error(tmp_path: Path) -> None:
         assert orchestrator._read_json_file(p) is None
 
 
+def test_progress_detail_from_subprocess_no_output() -> None:
+    p = subprocess.CompletedProcess(["x"], 1, stdout="", stderr="")
+    assert orchestrator._progress_detail_from_subprocess(p) == "no_output"
+
+
+def test_progress_detail_from_subprocess_prefers_stderr_when_distinct() -> None:
+    p = subprocess.CompletedProcess(["x"], 1, stdout="out", stderr="gh: label not found")
+    assert orchestrator._progress_detail_from_subprocess(p) == "gh: label not found\n---\nout"
+
+
+def test_progress_detail_from_subprocess_stdout_only() -> None:
+    p = subprocess.CompletedProcess(["x"], 1, stdout="docker log line\n", stderr="")
+    assert orchestrator._progress_detail_from_subprocess(p) == "docker log line"
+
+
+def test_progress_detail_from_subprocess_truncates() -> None:
+    long_out = "a" * 100
+    p = subprocess.CompletedProcess(["x"], 1, stdout=long_out, stderr="")
+    d = orchestrator._progress_detail_from_subprocess(p, max_chars=20)
+    assert d.startswith("...(truncated, 100 chars total)")
+    assert d.endswith("a" * 20)
+
+
 def test_load_pr_draft_malformed_json_uses_defaults(tmp_path: Path) -> None:
     iynx = tmp_path / ".iynx"
     iynx.mkdir()

tests/test_pr_review_followup.py

@@ -12,9 +12,7 @@
 
 
 def test_parse_pr_ref_url() -> None:
-    v, o, r, n = prf.parse_pr_ref(
-        "https://github.com/foo/bar/pull/99", None, None
-    )
+    v, o, r, n = prf.parse_pr_ref("https://github.com/foo/bar/pull/99", None, None)
     assert v == "https://github.com/foo/bar/pull/99"
     assert o == "foo" and r == "bar" and n == 99
 
@@ -42,9 +40,7 @@ def test_parse_pr_ref_invalid() -> None:
 
 
 def test_owner_repo_from_pr_json() -> None:
-    o, r = prf.owner_repo_from_pr_json(
-        {"baseRepository": {"nameWithOwner": "cli/cli"}}
-    )
+    o, r = prf.owner_repo_from_pr_json({"baseRepository": {"nameWithOwner": "cli/cli"}})
     assert o == "cli" and r == "cli"
 
 
@@ -86,7 +82,9 @@ def test_resolve_output_with_override(tmp_path: Path) -> None:
     assert p.is_file()
 
 
-def test_resolve_output_default_requires_gitignore(tmp_path: Path, monkeypatch: pytest.MonkeyPatch) -> None:
+def test_resolve_output_default_requires_gitignore(
+    tmp_path: Path, monkeypatch: pytest.MonkeyPatch
+) -> None:
     monkeypatch.chdir(tmp_path)
     subprocess_run = __import__("subprocess").run
     import subprocess
@@ -112,9 +110,7 @@ def fake_run(cmd: list, **kw):  # type: ignore[no-untyped-def]
         return subprocess.CompletedProcess(cmd, 1, "", "err")
 
     with patch("pr_review_followup.subprocess.run", side_effect=fake_run):
-        p, _ = prf.resolve_output_path(
-            output_cli=None, env_path=None, repo_root=tmp_path
-        )
+        p, _ = prf.resolve_output_path(output_cli=None, env_path=None, repo_root=tmp_path)
     assert p.name == "pr-review-feedback.md"
     assert ".iynx" in str(p)
 

tests/test_pr_stats.py

@@ -30,18 +30,20 @@ def test_build_search_q_without_label() -> None:
 
 
 def test_repo_from_repository_url() -> None:
-    assert pr_stats._repo_from_repository_url(
-        "https://api.github.com/repos/foo/bar"
-    ) == ("foo", "bar")
+    assert pr_stats._repo_from_repository_url("https://api.github.com/repos/foo/bar") == (
+        "foo",
+        "bar",
+    )
 
 
 def test_repo_from_issue_item_fallbacks() -> None:
     assert pr_stats._repo_from_issue_item(
         {"number": 1, "html_url": "https://github.com/foo/bar/pull/99"}
     ) == ("foo", "bar")
-    assert pr_stats._repo_from_issue_item(
-        {"number": 1, "repository": {"full_name": "a/b"}}
-    ) == ("a", "b")
+    assert pr_stats._repo_from_issue_item({"number": 1, "repository": {"full_name": "a/b"}}) == (
+        "a",
+        "b",
+    )
     assert pr_stats._repo_from_issue_item({"number": 1}) is None
 
 
@@ -163,7 +165,9 @@ def test_result_to_json_omits_empty_by_repo() -> None:
     assert "by_repo" not in d
 
 
-def test_json_output_schema(monkeypatch: pytest.MonkeyPatch, capsys: pytest.CaptureFixture[str]) -> None:
+def test_json_output_schema(
+    monkeypatch: pytest.MonkeyPatch, capsys: pytest.CaptureFixture[str]
+) -> None:
     monkeypatch.setenv("GITHUB_TOKEN", "tok")
     monkeypatch.setenv("NO_COLOR", "1")