From 095b1c4f50acb4603cf27bb6fff5ca5f94a7e0d2 Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Fri, 30 Oct 2026 21:09:24 +0800 Subject: [PATCH 1/6] fix(runtime): recover the published startup diagnostic after the ready budget A managed runtime publishes its typed startup diagnostic when it gives up, so the host could only read the envelope after the child had already exited. On a loaded runner the child was still running when the ready budget expired, so the host terminated it and reported the generic runtime_startup_timeout instead of the mutation_lock_timeout the runtime had already computed. That is the assertion the Windows lane produced. Give a runtime that is still running at the ready budget a bounded window to publish its locator or its typed diagnostic, and read the published envelope during that window. The window is one more ready budget, so no new budget enters the code and a startup attempt waits at most twice the ready budget. When the window closes with nothing published the runtime is terminated and the generic timeout is still reported. A runtime that publishes its locator inside the window is now accepted instead of terminated, and the published envelope stays authoritative for the caller: mutation_lock_timeout reaches the shared remediation in start_goal.py where runtime_startup_timeout had its own text. Signed-off-by: xiaoan17 --- loopx/control_plane/effect_runtime.py | 99 +++++++++++++-- .../test_effect_runtime_integration.py | 115 ++++++++++++++++++ 2 files changed, 203 insertions(+), 11 deletions(-) diff --git a/loopx/control_plane/effect_runtime.py b/loopx/control_plane/effect_runtime.py index 873fd6f0be..29c17e5100 100644 --- a/loopx/control_plane/effect_runtime.py +++ b/loopx/control_plane/effect_runtime.py @@ -73,6 +73,13 @@ MAX_STARTUP_DIAGNOSTIC_BYTES = 8 * 1024 STARTUP_LOCK_TIMEOUT_SECONDS = 15.0 STARTUP_POLL_SECONDS = 0.025 +# A managed runtime publishes its typed startup diagnostic when it gives up, +# so the host can only recover the exact code after that publication. When the +# ready budget expires while the runtime is still running, the host gives it +# one more ready budget to publish and exit instead of discarding a diagnostic +# the runtime already computed. The window reuses the ready budget the +# repository already owns rather than introducing an unrelated number. +STARTUP_DIAGNOSTIC_GRACE_SECONDS = STARTUP_READY_TIMEOUT_SECONDS RUNTIME_LOCATOR_PERMISSION_RETRIES = 3 RUNTIME_RETRY_SETTLE_SECONDS = 0.25 RUNTIME_LOCATOR_RECOVERY_TIMEOUT_SECONDS = 1.0 @@ -1156,6 +1163,66 @@ def _startup_diagnostic(raw: bytes) -> tuple[str, str] | None: return None +def _published_startup_failure( + startup_stderr: IO[bytes], +) -> EffectRuntimeStartupError | None: + """Return the typed failure a managed runtime published, if it published one. + + The runtime publishes its startup envelope before it exits, so the + envelope is authoritative even while the runtime is still running. Other + stderr content, such as a Node.js stack trace, is not a typed diagnostic + and must not be reported as one. + """ + + diagnostic = _startup_diagnostic(_read_startup_stderr(startup_stderr)) + if diagnostic is None: + return None + code, message = diagnostic + if code == "runtime_host_permission_denied": + return EffectRuntimeHostPermissionError() + return EffectRuntimeStartupError(message, diagnostic_code=code) + + +def _await_startup_publication( + process: subprocess.Popen[bytes], + startup_stderr: IO[bytes], + *, + info_path: Path, + fingerprint: str, + deadline: float, +) -> dict[str, Any] | None: + """Wait for a running runtime to publish its locator or its diagnostic. + + Returns the locator the runtime published. Raises the typed failure the + runtime published, or the stable exit diagnostic when it exits without + one. Returns None when the deadline passes with neither. + """ + + while time.monotonic() < deadline: + try: + info = _read_info(info_path, fingerprint=fingerprint) + except EffectRuntimeHostPermissionError: + if process.poll() is None: + process.terminate() + raise + if info is not None: + return info + exit_code = process.poll() + failure = _published_startup_failure(startup_stderr) + if failure is not None: + if exit_code is None: + process.terminate() + raise failure + if exit_code is not None: + raise EffectRuntimeStartupError( + "TypeScript Effect runtime exited before becoming ready " + f"(exit_code={exit_code})", + diagnostic_code="runtime_exited_before_ready", + ) + time.sleep(STARTUP_POLL_SECONDS) + return None + + def _start_runtime(*, fingerprint: str, info_path: Path) -> dict[str, Any]: runtime_dir = info_path.parent runtime_dir.mkdir(parents=True, exist_ok=True, mode=0o700) @@ -1261,23 +1328,33 @@ def _start_runtime(*, fingerprint: str, info_path: Path) -> dict[str, Any]: return info exit_code = process.poll() if exit_code is not None: - diagnostic = _startup_diagnostic( - _read_startup_stderr(startup_stderr) - ) - if diagnostic is not None: - code, message = diagnostic - if code == "runtime_host_permission_denied": - raise EffectRuntimeHostPermissionError() - raise EffectRuntimeStartupError( - message, - diagnostic_code=code, - ) + failure = _published_startup_failure(startup_stderr) + if failure is not None: + raise failure raise EffectRuntimeStartupError( "TypeScript Effect runtime exited before becoming ready " f"(exit_code={exit_code})", diagnostic_code="runtime_exited_before_ready", ) time.sleep(STARTUP_POLL_SECONDS) + # The runtime is still running when the ready budget expires, so it + # may yet publish its locator or the diagnostic it has already + # computed. Give it a bounded window to do either before the host + # reports a generic timeout and terminates it. + info = _await_startup_publication( + process, + startup_stderr, + info_path=info_path, + fingerprint=fingerprint, + deadline=time.monotonic() + STARTUP_DIAGNOSTIC_GRACE_SECONDS, + ) + if info is not None: + return info + failure = _published_startup_failure(startup_stderr) + if failure is not None: + if process.poll() is None: + process.terminate() + raise failure if process.poll() is None: process.terminate() raise EffectRuntimeStartupError( diff --git a/tests/control_plane/test_effect_runtime_integration.py b/tests/control_plane/test_effect_runtime_integration.py index 549e61d602..65fc5a0b28 100644 --- a/tests/control_plane/test_effect_runtime_integration.py +++ b/tests/control_plane/test_effect_runtime_integration.py @@ -1250,6 +1250,121 @@ def capture(stream): assert json.loads(lock_path.read_text()) == lock_owner +def test_a_doomed_runtime_keeps_its_exact_code_after_the_ready_budget( + tmp_path: Path, + monkeypatch, +) -> None: + """A runtime that publishes after the ready budget keeps its exact code. + + The managed runtime publishes its typed startup diagnostic when it gives + up, which for a live mutation lock happens after the TypeScript + mutation-lock budget. A host that stops waiting at the ready budget + discards that diagnostic and reports a generic timeout instead. + """ + + marker = "private-locator-fixture" + runtime_dir = tmp_path / marker + runtime_dir.mkdir(mode=0o700) + monkeypatch.setattr(effect_runtime, "_runtime_dir", lambda: runtime_dir) + info_path = effect_runtime._runtime_info_path(effect_runtime._runtime_fingerprint()) + lock_path = Path(f"{info_path}.ts-effect.lock") + lock_owner = {"pid": os.getpid(), "token": "live-owner"} + lock_path.write_text(json.dumps(lock_owner), encoding="utf-8") + # The ready budget expires before the runtime has waited out the + # TypeScript mutation-lock budget, which is the case this covers. + monkeypatch.setattr(effect_runtime, "STARTUP_READY_TIMEOUT_SECONDS", 1.0) + + published: list[bytes] = [] + read_stderr = effect_runtime._read_startup_stderr + + def capture(stream): + raw = read_stderr(stream) + if raw: + published.append(raw) + return raw + + monkeypatch.setattr(effect_runtime, "_read_startup_stderr", capture) + with pytest.raises(effect_runtime.EffectRuntimeStartupError) as raised: + effect_runtime.effect_runtime_result("runtime.ping", {}, retry_safe=False) + + assert raised.value.diagnostic_code == "mutation_lock_timeout" + assert "could not publish its startup locator" in str(raised.value) + assert published, "the runtime must publish its diagnostic before it exits" + envelopes = [ + json.loads(line) + for line in published[-1].decode("utf-8").splitlines() + if line.strip().startswith("{") + ] + assert envelopes[-1] == { + "schema_version": effect_runtime.EFFECT_RUNTIME_STARTUP_ERROR_SCHEMA_VERSION, + "code": "mutation_lock_timeout", + "message": str(raised.value), + } + assert marker not in published[-1].decode() + assert lock_owner["token"] not in published[-1].decode() + assert not info_path.exists(), "a failed publisher must not claim readiness" + assert json.loads(lock_path.read_text()) == lock_owner + + +def test_a_runtime_that_never_publishes_still_reports_a_bounded_timeout( + tmp_path: Path, + monkeypatch, +) -> None: + """The diagnostic grace window stays bounded and still times out. + + A runtime that publishes nothing must not hold its caller open: the host + waits one bounded grace window, terminates the runtime and reports the + generic timeout. + """ + + runtime_dir = tmp_path / "runtime" + runtime_dir.mkdir() + fingerprint = "f" * 64 + info_path = runtime_dir / "runtime.json" + clock = {"monotonic": 0.0} + terminated: list[bool] = [] + + class _RunningProcess: + def poll(self): + return None + + def terminate(self) -> None: + terminated.append(True) + + def sleep(seconds: float) -> None: + clock["monotonic"] += seconds + + monkeypatch.setattr(effect_runtime, "_read_info", lambda *_args, **_kwargs: None) + monkeypatch.setattr(effect_runtime, "_node_executable", lambda: "node") + monkeypatch.setattr( + effect_runtime.subprocess, + "Popen", + lambda *_args, **_kwargs: _RunningProcess(), + ) + monkeypatch.setattr(effect_runtime, "_read_startup_stderr", lambda _stream: b"") + monkeypatch.setattr(effect_runtime, "STARTUP_READY_TIMEOUT_SECONDS", 1.0) + monkeypatch.setattr(effect_runtime, "STARTUP_POLL_SECONDS", 0.5) + monkeypatch.setattr( + effect_runtime, + "time", + SimpleNamespace( + monotonic=lambda: clock["monotonic"], + sleep=sleep, + time=time.time, + ), + ) + + with pytest.raises(effect_runtime.EffectRuntimeStartupError) as raised: + effect_runtime._start_runtime(fingerprint=fingerprint, info_path=info_path) + + assert raised.value.diagnostic_code == "runtime_startup_timeout" + assert terminated, "a runtime that never publishes must be terminated" + assert clock["monotonic"] == pytest.approx( + effect_runtime.STARTUP_READY_TIMEOUT_SECONDS + + effect_runtime.STARTUP_DIAGNOSTIC_GRACE_SECONDS + ) + + def test_runtime_ping_survives_denied_post_publication_chmod( tmp_path: Path, monkeypatch, From a85bf59adce8a30a94d81ca7a5e02ee8de198569 Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Fri, 30 Oct 2026 21:09:42 +0800 Subject: [PATCH 2/6] docs(rfc): record the startup diagnostic grace window Record the gap the repair closes, the two acceptance points and how they are met, what the entry deliberately does not establish, and the validation that pins the behaviour. The repair is a diagnostic improvement rather than a correctness repair, and the entry does not qualify Windows CI as passing. Signed-off-by: xiaoan17 --- docs/architecture/rfcs/STATUS.md | 2 +- docs/architecture/rfcs/STATUS.zh-CN.md | 2 +- ...6-10-30-s2-s12-startup-diagnostic-grace.md | 143 ++++++++++++++++++ ...0-s2-s12-startup-diagnostic-grace.zh-CN.md | 116 ++++++++++++++ 4 files changed, 261 insertions(+), 2 deletions(-) create mode 100644 docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md create mode 100644 docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md diff --git a/docs/architecture/rfcs/STATUS.md b/docs/architecture/rfcs/STATUS.md index f67af4274c..e98c033cd8 100644 --- a/docs/architecture/rfcs/STATUS.md +++ b/docs/architecture/rfcs/STATUS.md @@ -54,7 +54,7 @@ appendix may keep dated history, but no dated log heading may precede it. | [RFC: Live Team Workspace v0](live-team-workspace-v0.md) | Accepted | none | — | | [RFC: Long-Horizon Harness Benchmark and Research Program v0](long-horizon-harness-benchmark-research-program-v0.md) | Accepted | none | — | | [RFC: Long-Running Agent Reliability Diagnostics and Governed Delivery v0](long-running-agent-reliability-diagnostics-governed-delivery-v0.md) | Accepted | none | — | -| [LoopX Overall Roadmap v0: Product, Collaboration, Technology and Delivery](loopx-overall-roadmap-v0.md) | Accepted | none | [1 entry](ledger/loopx-overall-roadmap-v0/) | +| [LoopX Overall Roadmap v0: Product, Collaboration, Technology and Delivery](loopx-overall-roadmap-v0.md) | Accepted | none | [2 entries](ledger/loopx-overall-roadmap-v0/) | | [Manager runtime profile v0](manager-runtime-profile-v0.md) | Accepted | none | — | | [RFC: Monorepo Distribution and Small-Kernel Runtime Composition (v0)](monorepo-distribution-split-v0.md) | Accepted | none | — | | [RFC: Obelisk Session Evidence Provider v0](obelisk-session-evidence-provider-v0.md) | Accepted | none | — | diff --git a/docs/architecture/rfcs/STATUS.zh-CN.md b/docs/architecture/rfcs/STATUS.zh-CN.md index 373aa3ef3c..2944938f69 100644 --- a/docs/architecture/rfcs/STATUS.zh-CN.md +++ b/docs/architecture/rfcs/STATUS.zh-CN.md @@ -51,7 +51,7 @@ | [RFC：团队实时工作区 v0](live-team-workspace-v0.zh-CN.md) | 已接受 | 无 | — | | [RFC：长程 Harness Benchmark 与研究计划 v0](long-horizon-harness-benchmark-research-program-v0.zh-CN.md) | 已接受 | 无 | — | | [RFC：长程 Agent 可靠性诊断与治理交付 v0](long-running-agent-reliability-diagnostics-governed-delivery-v0.zh-CN.md) | 已接受 | 无 | — | -| [LoopX 整体路线总纲 v0：产品、协作、技术与交付](loopx-overall-roadmap-v0.zh-CN.md) | 已接受 | 无 | [1 条](ledger/loopx-overall-roadmap-v0/) | +| [LoopX 整体路线总纲 v0：产品、协作、技术与交付](loopx-overall-roadmap-v0.zh-CN.md) | 已接受 | 无 | [2 条](ledger/loopx-overall-roadmap-v0/) | | [Manager runtime profile v0 / 管家运行模式 v0](manager-runtime-profile-v0.zh-CN.md) | 已接受 | 无 | — | | [RFC：Monorepo 发行拆分与小内核运行时装配（v0）](monorepo-distribution-split-v0.zh-CN.md) | 已接受 | 无 | — | | [RFC：Obelisk Session Evidence Provider v0](obelisk-session-evidence-provider-v0.zh-CN.md) | 已接受 | 无 | — | diff --git a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md new file mode 100644 index 0000000000..7f2cd581a6 --- /dev/null +++ b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md @@ -0,0 +1,143 @@ +# S2/S12 startup diagnostic: recovering the published code after the ready budget (2026-10-30) + +This entry records a repair to the managed runtime startup path. It extends +the [2026-10-04 startup diagnostic +checkpoint](2026-10-04-s2-s12-startup-diagnostic.md) and corrects the +delivery of a diagnostic the runtime had already computed. + +## The gap + +The 2026-10-04 checkpoint established that a fixture holding a live mutation +lock must fail with the exact `mutation_lock_timeout` code, and it explicitly +did not qualify Windows. The Windows lane fails intermittently on operations +that start the Effect runtime and wait for it to become ready, and one +retrievable run of that lane (`1e3401591`) failed with + +``` +assert 'runtime_startup_timeout' == 'mutation_lock_timeout' +``` + +`runtime_startup_timeout` is produced only when the ready budget expires while +the child is still running, so on that run the child had not exited inside +15 s. The same job's pytest step ran 439 cases in 5 min 31 s, and the chunk +holding the failure took two minutes against six seconds for the chunk before +it, so the runner was heavily loaded. + +The startup cost itself has ample headroom. Measured on the Windows runner at +`2f544f9692` and on macOS at `d3d9ad209d`: + +| Host | Ready startup | Live-lock total | Diagnostic delivered | +| --- | --- | --- | --- | +| Windows (`nt`) | 0.406 s | 5.813 s | `mutation_lock_timeout` | +| macOS (`posix`) | 0.170 s | 5.140 s | `mutation_lock_timeout` | + +`STARTUP_READY_TIMEOUT_SECONDS` is 15.0 and the TypeScript +`MUTATION_LOCK_TIMEOUT_MS` is 5,000. Neither budget is the constraint, and +neither is widened here. + +The exact code is lost rather than absent. The TypeScript runtime computes the +typed code and publishes it to stderr when it gives up; Python reads that +envelope only when `process.poll()` shows the child has already exited, and +otherwise terminates the child at the budget and reports the generic +`runtime_startup_timeout`. The envelope is published at the moment the child +exits, so there is nothing typed to read while the child is still running: at +one second, three seconds and five seconds the child is still running and +stderr holds zero bytes, and the envelope appears only once it exits, at about +5.8 s, together with exit code 2. + +The host therefore discarded a diagnostic the runtime had already computed and +reported a generic timeout instead. The diagnostic difference is the whole +point of the typed envelope: `loopx/cli_commands/start_goal.py` gives +`runtime_startup_timeout` its own remediation text, while `mutation_lock_timeout` +falls through to the shared default, so the two codes lead the caller to +different repairs. + +## The repair + +`loopx/control_plane/effect_runtime.py` now gives a runtime that is still +running when the ready budget expires a bounded window in which it may publish +either its locator or its typed diagnostic. The host reads the published +envelope during that window and reports the exact code it carries. + +The window is bounded by a budget the repository already owns rather than by a +new number: `STARTUP_DIAGNOSTIC_GRACE_SECONDS` is one more ready budget, so a +single startup attempt waits at most twice `STARTUP_READY_TIMEOUT_SECONDS`. +When the window closes with nothing published, the runtime is terminated and +the generic `runtime_startup_timeout` is reported, so the wait stays bounded. + +A runtime that publishes its locator inside the window is now accepted instead +of terminated. Before the repair, a runtime that was merely slow was killed at +the ready budget; that outcome is unchanged in kind, only later in time. + +## The two acceptance points + +The repair leaves two acceptance points, and this entry meets both. + +**The grace window has to be bounded by something the repository already owns.** +It is: the window is one more ready budget, `STARTUP_DIAGNOSTIC_GRACE_SECONDS += STARTUP_READY_TIMEOUT_SECONDS`, so no new budget enters the code and the +total wait per attempt is at most twice the ready budget the repository +already defined. + +**The user-visible guidance changes with the code.** A caller that receives +the exact `mutation_lock_timeout` is now told to repair or reinstall LoopX, +where it was previously told that startup timed out. That difference is the +intended consequence of recovering the exact code, and it is read as such +rather than as a regression. + +## What this entry does not establish + +No budget change is proposed or qualified: the measurements show both budgets +are sufficient, and neither is widened. No owner-liveness change is made: the +lock in this path is held by a live owner, so the owner-liveness check +behaves correctly for it. + +The repair is a diagnostic improvement, not a correctness repair. The runtime +still fails to publish its locator in the live-lock case, and the caller still +fails to start; what changes is that the caller is now told the reason. This +entry does not qualify Windows CI as passing, and the intermittent failure +set is preserved rather than reclassified. + +A failed startup now blocks its caller for up to twice the ready budget +instead of once. `effect_runtime_request` retries a startup failure once for a +retry-safe call, so a caller that is failing to start can wait for two +attempts. The retry policy is unchanged here. + +## Evidence + +The repair is pinned by a test that reproduces the observed failure without a +Windows runner. With the ready budget shortened and a live mutation lock held +by the current process, the pre-repair host reports the generic timeout, and +the assertion is the one the Windows lane produced: + +``` +assert 'runtime_startup_timeout' == 'mutation_lock_timeout' +``` + +After the repair the same fixture delivers the exact +`mutation_lock_timeout`, the published envelope, and the preserved live lock. +A second test pins the bound: a runtime that publishes nothing is terminated +and still reports `runtime_startup_timeout` after exactly one ready budget +plus one grace window. + +## Validation + +``` +uv run --extra test python -m pytest \ + tests/control_plane/test_effect_runtime_integration.py -q 102 passed, 1 skipped +uv run --extra test python -m pytest \ + tests/control_plane/test_effect_runtime_host_permission.py \ + tests/control_plane/test_effect_runtime_node_probe.py \ + tests/control_plane/test_start_goal_compact_projection.py \ + tests/test_chat_server_cors.py -q 201 passed +python examples/docs-governance-smoke.py docs-governance-smoke ok +python scripts/generate_rfc_status_index.py --check clean +scripts/check_rfc_bilingual.py --base origin/main --head HEAD passed +uv run --extra test loopx canary premerge --from-git-diff --git-diff-base origin/main +``` + +The measurement that motivated this repair is re-derivable rather than +taken on trust: the commit that produced the two figures is reachable as +`codex/measurement-archive` on the fork, and it raises a deliberate +`AssertionError` carrying the measurement, because the Windows lane runs pytest +without `-s` and would otherwise capture the output. diff --git a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md new file mode 100644 index 0000000000..cc4284c3e9 --- /dev/null +++ b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md @@ -0,0 +1,116 @@ +# S2/S12 启动诊断：在就绪预算之后取回已发布的诊断码（2026-10-30） + +本条目记录对受管 runtime 启动路径的一次修复。它扩展 +[2026-10-04 启动诊断检查点](2026-10-04-s2-s12-startup-diagnostic.zh-CN.md)， +并修正一个 runtime 已经算好、却没有送达的诊断。 + +## 缺口 + +2026-10-04 那个检查点确立：持有活 mutation lock 的 fixture 必须以精确的 +`mutation_lock_timeout` 码失败，并且明确没有给 Windows 资格。Windows lane +在"启动 Effect runtime 并等待其就绪"这类操作上间歇失败，其中一次仍可获取的 +run（`1e3401591`）以 + +``` +assert 'runtime_startup_timeout' == 'mutation_lock_timeout' +``` + +失败。`runtime_startup_timeout` 只在"就绪预算耗尽而子进程仍在运行"时产生， +因此那次运行里子进程没有在 15 秒内退出。同一个 job 的 pytest 步骤用 5 分 31 秒 +跑完 439 个用例，含失败的那一段用两分钟，而前一段只用六秒，说明 runner 负载很重。 + +启动成本本身有充裕余量。分别在 Windows runner 的 `2f544f9692` 与 macOS 的 +`d3d9ad209d` 上测量： + +| 宿主 | 就绪启动 | live-lock 总计 | 送达的诊断 | +| --- | --- | --- | --- | +| Windows (`nt`) | 0.406 秒 | 5.813 秒 | `mutation_lock_timeout` | +| macOS (`posix`) | 0.170 秒 | 5.140 秒 | `mutation_lock_timeout` | + +`STARTUP_READY_TIMEOUT_SECONDS` 为 15.0，TypeScript 的 `MUTATION_LOCK_TIMEOUT_MS` +为 5,000。两个预算都不是约束，这里也不放宽任何一个。 + +精确码是丢失了，而不是没有产生。TypeScript runtime 在放弃时算出类型化码并把它 +发布到 stderr；Python 只在 `process.poll()` 显示子进程已经退出时才读那份信封， +否则就在预算处终止子进程并报告通用的 `runtime_startup_timeout`。信封是在子进程 +退出那一刻才发布的，因此子进程仍在运行时根本没有类型化的内容可读：在 1 秒、 +3 秒和 5 秒，子进程仍在运行且 stderr 有 0 字节；信封只在子进程退出时才出现， +约 5.8 秒，与退出码 2 同时。 + +于是宿主丢弃了一个 runtime 已经算好的诊断，改报一个通用超时。而类型化信封的全部 +意义正在于这个诊断差异：`loopx/cli_commands/start_goal.py` 为 +`runtime_startup_timeout` 准备了专门的修复提示，而 `mutation_lock_timeout` +落到共享兜底提示上，两个码会把调用方引向不同的修复动作。 + +## 修法 + +`loopx/control_plane/effect_runtime.py` 现在会给"就绪预算耗尽时仍在运行"的 +runtime 一个有界窗口，让它在此期间发布自己的 locator 或类型化诊断。宿主在这个 +窗口里读取已发布的信封，并报告它携带的精确码。 + +窗口由仓库已经拥有的某个预算来界定，而不是引入一个新数字： +`STARTUP_DIAGNOSTIC_GRACE_SECONDS` 就是一个就绪预算，因此一次启动尝试最多等待 +两倍 `STARTUP_READY_TIMEOUT_SECONDS`。当窗口关闭时仍没有发布任何内容，runtime +会被终止并报告通用的 `runtime_startup_timeout`，等待因此仍然有界。 + +在窗口内发布 locator 的 runtime 现在会被接受，而不是被终止。修法之前，只是启动 +偏慢的 runtime 会在就绪预算处被杀掉；这个结果在种类上未变，只是发生得更晚。 + +## 两个验收点 + +这次修法留下两个验收点，本条目两条都满足。 + +**收尾窗口必须由仓库已经拥有的东西来界定。** 它是的：窗口就是一个就绪预算， +`STARTUP_DIAGNOSTIC_GRACE_SECONDS = STARTUP_READY_TIMEOUT_SECONDS`，因此代码里 +没有引入新预算，每次尝试的总等待至多是仓库已经定义的就绪预算的两倍。 + +**用户可见的指引会随诊断码一起改变。** 收到精确 `mutation_lock_timeout` 的调用方， +现在会被告知修复或重装 LoopX，而此前被告知"启动超时"。这个差异是取回精确码的 +预期后果，应当被这样理解，而不是当作回归。 + +## 本条目没有确立什么 + +这里不提出也不认证任何预算变更：实测表明两个预算都足够，两者都未放宽。这里也 +不做属主存活性变更：这条路径上的锁由一个存活属主持有，属主存活判定对它行为正确。 + +这次修法是诊断信息上的改进，不是正确性修复。在 live-lock 情形下，runtime 仍然 +无法发布其 locator，调用方仍然启动失败；改变的是调用方现在被告知了原因。本条目 +不构成 Windows CI 通过的资格，间歇失败集合被原样保留，没有被重新归类。 + +启动失败现在最多阻塞调用方两个就绪预算，而此前是一个。 +`effect_runtime_request` 对可重试的调用会在启动失败后重试一次，因此一个正在启动 +失败的调用方最多可能等待两次尝试。这里的重试策略没有改变。 + +## 证据 + +这次修法由一个测试固定下来：它不需要 Windows runner 就能复现已观察到的失败。把 +就绪预算调短并让当前进程持有一个活的 mutation lock，修法之前的宿主会报告通用 +超时，其断言正是 Windows lane 产生过的那一条： + +``` +assert 'runtime_startup_timeout' == 'mutation_lock_timeout' +``` + +修法之后，同一个 fixture 送达精确的 `mutation_lock_timeout`、已发布的信封，以及 +被保留的活锁。第二个测试固定住边界：什么都不发布的 runtime 会被终止，并且在正好 +一个就绪预算加一个收尾窗口之后仍然报告 `runtime_startup_timeout`。 + +## 验证 + +``` +uv run --extra test python -m pytest \ + tests/control_plane/test_effect_runtime_integration.py -q 102 passed, 1 skipped +uv run --extra test python -m pytest \ + tests/control_plane/test_effect_runtime_host_permission.py \ + tests/control_plane/test_effect_runtime_node_probe.py \ + tests/control_plane/test_start_goal_compact_projection.py \ + tests/test_chat_server_cors.py -q 201 passed +python examples/docs-governance-smoke.py docs-governance-smoke ok +python scripts/generate_rfc_status_index.py --check clean +scripts/check_rfc_bilingual.py --base origin/main --head HEAD passed +uv run --extra test loopx canary premerge --from-git-diff --git-diff-base origin/main +``` + +促成这次修法的测量可以被重新推导，而不必只能被采信：产生那两个数字的提交在 fork 的 +`codex/measurement-archive` 分支上仍然可达，它用一个刻意抛出的 `AssertionError` +携带测量值，因为 Windows lane 跑 pytest 时没有 `-s`，否则输出会被吞掉。 From 2fd0ce7ec7e74ba911d8f57a1a84645178e812e6 Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Fri, 30 Oct 2026 22:51:05 +0800 Subject: [PATCH 3/6] ci: retrigger the browser lane after a transient render-budget outlier The dashboard-browser (2) lane failed once on a single lens-switch sample: 1345 ms against the frozen 1 s budget, while the other four samples in the same run measured 511-765 ms. The same lane on two other branches in the same window measured 377-765 ms, and the failing run's `checks` failure is its consequence: a failed browser lane skips dashboard-acceptance, and the aggregate gate then requires that job to have succeeded. The budget is frozen and stays as it is. The smoke renders an in-page fake runtime over synthetic status and map data, so this branch's Python runtime startup change has no path to the render timing. No content change. Signed-off-by: xiaoan17 From 304f938bb31ed7e23fce4bd79c32403813221adc Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Fri, 30 Oct 2026 23:29:43 +0800 Subject: [PATCH 4/6] ci: retrigger the browser lane after a second render-budget outlier The same scenario failed again on a fresh runner. The loaded lens switches measured 736, 521, 872, 977 and 1061 ms against the frozen 1 s budget; the first attempt measured 733, 511, 765, 1345 and 617 ms. Other branches' runs of the same lane in the same window measured maxima of 673, 713, 775 and 817 ms, so the budget carries about 30% headroom on a healthy runner and none on a loaded one. This branch's diff is Python-only. The dashboard-browser lane serves the dashboard with vite and answers the API inside the page, so it never executes the changed Python path, and the managed Effect runtime is not started by that lane. The shard-2 job ran about 20% slower end to end than another branch's shard-2 job in the same window, with every scenario duration higher, which is the signature of a loaded runner rather than a code cause. The frozen budget is not touched, and neither failure is relabelled. No content change. Signed-off-by: xiaoan17 From 5c8b8f18f6b01ac5fb2e6b733375e0bd8c3773be Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Fri, 30 Oct 2026 23:57:43 +0800 Subject: [PATCH 5/6] ci: retrigger the browser lane after the shard-2 pattern was matched elsewhere The third attempt failed the same way (814, 792, 612, 607, 1213 ms), and the shard-2 job repeated its shape exactly: 22 scenarios in 788 s, against 644 s for 27 scenarios in shard 1 of the same run. That shape is not this branch's. The run of codex/quota-demand-loading from 08:12 today failed the same assertion on the same scenario (733, 551, 1515, 983, 592 ms) with the same split: 22 scenarios in 800 s for shard 2 against 831 s for 27 scenarios in shard 1, and 475 s for shard 3. A loaded shard-2 runner ends the shard early, and the loaded lens switch is what crosses the frozen budget. The budget is not touched and the earlier failures are not relabelled. No content change. Signed-off-by: xiaoan17 From ed1c2ae62f7e64b242f6c323fad72f43b5754208 Mon Sep 17 00:00:00 2001 From: xiaoan17 Date: Sat, 31 Oct 2026 00:04:07 +0800 Subject: [PATCH 6/6] fix(rfc): keep the startup failure's cause undetermined, and pin the missed exit The review is right about the attribution. The baseline reads the published envelope only when a poll *inside* the ready loop reports an exit; after the loop it polls once more, but only to decide whether to terminate the child, and it then always reports the generic timeout. So the recorded failure does not distinguish a child that had not published yet from a child that had published and exited without the parent observing it, and the entry claimed the first one as established. State both possibilities and keep the historical attribution undetermined. The repair covers both, so it does not depend on which one the recorded failure was: a late publication is read inside the grace window, and an envelope that was already published is read without waiting for the child to exit. Pin the second case with a test. The exit lands after the parent's last in-loop poll; the baseline reports the generic timeout for an envelope that is already in the capture, and the repair reports the exact code. Both new tests report the generic timeout on the baseline. Also state that the added wait is the startup path's own cost, not an absolute ceiling for the whole call: the startup lock, the Node probe and the outer retry each carry their own. Signed-off-by: xiaoan17 --- ...6-10-30-s2-s12-startup-diagnostic-grace.md | 61 +++++++++++++------ ...0-s2-s12-startup-diagnostic-grace.zh-CN.md | 42 ++++++++----- .../test_effect_runtime_integration.py | 61 +++++++++++++++++++ 3 files changed, 130 insertions(+), 34 deletions(-) diff --git a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md index 7f2cd581a6..8e4f32793c 100644 --- a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md +++ b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.md @@ -17,11 +17,18 @@ retrievable run of that lane (`1e3401591`) failed with assert 'runtime_startup_timeout' == 'mutation_lock_timeout' ``` -`runtime_startup_timeout` is produced only when the ready budget expires while -the child is still running, so on that run the child had not exited inside -15 s. The same job's pytest step ran 439 cases in 5 min 31 s, and the chunk -holding the failure took two minutes against six seconds for the chunk before -it, so the runner was heavily loaded. +`runtime_startup_timeout` is produced whenever the parent does not observe the +child's exit inside the ready loop. The baseline reads the published envelope +only when a poll *within* that loop reports an exit; after the loop it polls +once more, but only to decide whether to terminate the child, and it then +always reports the generic timeout. The historical run therefore does not +distinguish two situations: the child had not published yet when the budget +expired, or the child had already published and exited and the parent had not +observed that exit before it left the loop. The same job's pytest step ran 439 +cases in 5 min 31 s, and the chunk holding the failure took two minutes +against six seconds for the chunk before it, so the runner was heavily loaded. +That load is a plausible contributor to a late publication, not a demonstrated +cause. The startup cost itself has ample headroom. Measured on the Windows runner at `2f544f9692` and on macOS at `d3d9ad209d`: @@ -37,13 +44,15 @@ neither is widened here. The exact code is lost rather than absent. The TypeScript runtime computes the typed code and publishes it to stderr when it gives up; Python reads that -envelope only when `process.poll()` shows the child has already exited, and -otherwise terminates the child at the budget and reports the generic -`runtime_startup_timeout`. The envelope is published at the moment the child -exits, so there is nothing typed to read while the child is still running: at -one second, three seconds and five seconds the child is still running and -stderr holds zero bytes, and the envelope appears only once it exits, at about -5.8 s, together with exit code 2. +envelope only when a poll inside the ready loop shows the child has already +exited, and otherwise terminates the child at the budget and reports the +generic `runtime_startup_timeout` without reading the capture again. The +envelope is published at the moment the child exits, so a child that has not +exited has published nothing to read: at one second, three seconds and five +seconds the child is still running and stderr holds zero bytes, and the +envelope appears only once it exits, at about 5.8 s, together with exit code 2. +A child that has published and exited leaves the envelope in the capture, and +the baseline leaves it unread. The host therefore discarded a diagnostic the runtime had already computed and reported a generic timeout instead. The diagnostic difference is the whole @@ -69,6 +78,11 @@ A runtime that publishes its locator inside the window is now accepted instead of terminated. Before the repair, a runtime that was merely slow was killed at the ready budget; that outcome is unchanged in kind, only later in time. +The repair covers both situations the historical record cannot separate: a +late publication is read inside the window, and an envelope that was already +published is read without waiting for the child to exit. It therefore does not +depend on knowing which of the two the recorded failure was. + ## The two acceptance points The repair leaves two acceptance points, and this entry meets both. @@ -101,14 +115,17 @@ set is preserved rather than reclassified. A failed startup now blocks its caller for up to twice the ready budget instead of once. `effect_runtime_request` retries a startup failure once for a retry-safe call, so a caller that is failing to start can wait for two -attempts. The retry policy is unchanged here. +attempts. The retry policy is unchanged here. That is the wait this startup +path adds, not an absolute ceiling for the whole call: the startup lock, the +Node probe and the outer retry each carry their own cost. ## Evidence -The repair is pinned by a test that reproduces the observed failure without a -Windows runner. With the ready budget shortened and a live mutation lock held -by the current process, the pre-repair host reports the generic timeout, and -the assertion is the one the Windows lane produced: +The repair is pinned by tests that reproduce the failure mode without a +Windows runner: the parent does not observe the runtime's published +diagnostic inside the ready loop. With the ready budget shortened and a live +mutation lock held by the current process, the pre-repair host reports the +generic timeout, and the assertion is the one the Windows lane produced: ``` assert 'runtime_startup_timeout' == 'mutation_lock_timeout' @@ -116,9 +133,13 @@ assert 'runtime_startup_timeout' == 'mutation_lock_timeout' After the repair the same fixture delivers the exact `mutation_lock_timeout`, the published envelope, and the preserved live lock. -A second test pins the bound: a runtime that publishes nothing is terminated -and still reports `runtime_startup_timeout` after exactly one ready budget -plus one grace window. +A second test pins the other situation the historical record cannot separate: +an envelope that the runtime published before the deadline but whose exit the +parent's poll missed is still read, because the parent polls once more after +the loop but the baseline never reads the capture again. Both tests report the +generic timeout on the baseline. A third test pins the bound: a runtime that +publishes nothing is terminated and still reports `runtime_startup_timeout` +after exactly one ready budget plus one grace window. ## Validation diff --git a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md index cc4284c3e9..70244dddb1 100644 --- a/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md +++ b/docs/architecture/rfcs/ledger/loopx-overall-roadmap-v0/2026-10-30-s2-s12-startup-diagnostic-grace.zh-CN.md @@ -15,9 +15,13 @@ run（`1e3401591`）以 assert 'runtime_startup_timeout' == 'mutation_lock_timeout' ``` -失败。`runtime_startup_timeout` 只在"就绪预算耗尽而子进程仍在运行"时产生， -因此那次运行里子进程没有在 15 秒内退出。同一个 job 的 pytest 步骤用 5 分 31 秒 -跑完 439 个用例，含失败的那一段用两分钟，而前一段只用六秒，说明 runner 负载很重。 +失败。`runtime_startup_timeout` 在宿主没有在就绪循环里观察到子进程退出时产生。 +基线只在该循环*内部*的轮询报告了退出时才去读已发布的信封；循环结束后它还会再 +轮询一次，但那只用来决定是否终止子进程，随后总是报通用的超时。因此那次历史运行 +无法区分两种情形：预算耗尽时子进程尚未发布，或者子进程其实已经发布并退出、而宿主 +在离开循环之前没有观察到那次退出。同一个 job 的 pytest 步骤用 5 分 31 秒跑完 439 +个用例，含失败的那一段用两分钟，而前一段只用六秒，说明 runner 负载很重。这种负载 +是"发布迟到"的一个合理成因，但不是被证明的根因。 启动成本本身有充裕余量。分别在 Windows runner 的 `2f544f9692` 与 macOS 的 `d3d9ad209d` 上测量： @@ -31,11 +35,12 @@ assert 'runtime_startup_timeout' == 'mutation_lock_timeout' 为 5,000。两个预算都不是约束，这里也不放宽任何一个。 精确码是丢失了，而不是没有产生。TypeScript runtime 在放弃时算出类型化码并把它 -发布到 stderr；Python 只在 `process.poll()` 显示子进程已经退出时才读那份信封， -否则就在预算处终止子进程并报告通用的 `runtime_startup_timeout`。信封是在子进程 -退出那一刻才发布的，因此子进程仍在运行时根本没有类型化的内容可读：在 1 秒、 -3 秒和 5 秒，子进程仍在运行且 stderr 有 0 字节；信封只在子进程退出时才出现， -约 5.8 秒，与退出码 2 同时。 +发布到 stderr；Python 只在就绪循环内部的轮询显示子进程已经退出时才读那份信封， +否则就在预算处终止子进程并报告通用的 `runtime_startup_timeout`，而且不会再去补读 +一次捕获文件。信封是在子进程退出那一刻才发布的，因此还没退出的子进程没有任何已 +发布的类型化内容可读：在 1 秒、3 秒和 5 秒，子进程仍在运行且 stderr 有 0 字节； +信封只在子进程退出时才出现，约 5.8 秒，与退出码 2 同时。而一个已经发布并退出的 +子进程会把信封留在捕获文件里，基线却不去读它。 于是宿主丢弃了一个 runtime 已经算好的诊断，改报一个通用超时。而类型化信封的全部 意义正在于这个诊断差异：`loopx/cli_commands/start_goal.py` 为 @@ -56,6 +61,10 @@ runtime 一个有界窗口，让它在此期间发布自己的 locator 或类型 在窗口内发布 locator 的 runtime 现在会被接受，而不是被终止。修法之前，只是启动 偏慢的 runtime 会在就绪预算处被杀掉；这个结果在种类上未变，只是发生得更晚。 +这次修法同时覆盖了历史记录无法区分的两种情形：迟到的发布会在窗口内被读到，而 +已经发布出去的信封不必等子进程退出就能被读到。因此修法的收益不依赖于判定那次 +记录在案的失败究竟属于哪一种。 + ## 两个验收点 这次修法留下两个验收点，本条目两条都满足。 @@ -79,21 +88,26 @@ runtime 一个有界窗口，让它在此期间发布自己的 locator 或类型 启动失败现在最多阻塞调用方两个就绪预算，而此前是一个。 `effect_runtime_request` 对可重试的调用会在启动失败后重试一次，因此一个正在启动 -失败的调用方最多可能等待两次尝试。这里的重试策略没有改变。 +失败的调用方最多可能等待两次尝试。这里的重试策略没有改变。这是这条启动路径额外 +增加的等待，并不是整个调用的绝对上限：启动锁、Node 探针和外层重试各有各的成本。 ## 证据 -这次修法由一个测试固定下来：它不需要 Windows runner 就能复现已观察到的失败。把 -就绪预算调短并让当前进程持有一个活的 mutation lock，修法之前的宿主会报告通用 -超时，其断言正是 Windows lane 产生过的那一条： +这次修法由若干测试固定下来：它们不需要 Windows runner 就能复现这一失败形态—— +宿主没有在就绪循环里观察到 runtime 已发布的诊断。把就绪预算调短并让当前进程持有 +一个活的 mutation lock，修法之前的宿主会报告通用超时，其断言正是 Windows lane +产生过的那一条： ``` assert 'runtime_startup_timeout' == 'mutation_lock_timeout' ``` 修法之后，同一个 fixture 送达精确的 `mutation_lock_timeout`、已发布的信封，以及 -被保留的活锁。第二个测试固定住边界：什么都不发布的 runtime 会被终止，并且在正好 -一个就绪预算加一个收尾窗口之后仍然报告 `runtime_startup_timeout`。 +被保留的活锁。第二个测试固定住历史记录无法区分的另一种情形：runtime 在截止之前 +已经发布、但退出没有被宿主的轮询观察到的信封，仍然会被读到——因为宿主在循环之后 +还会再轮询一次，而基线却不会再去读捕获文件。这两个测试在基线上都报通用超时。 +第三个测试固定住边界：什么都不发布的 runtime 会被终止，并且在正好一个就绪预算加 +一个收尾窗口之后仍然报告 `runtime_startup_timeout`。 ## 验证 diff --git a/tests/control_plane/test_effect_runtime_integration.py b/tests/control_plane/test_effect_runtime_integration.py index 65fc5a0b28..9a259cf3d2 100644 --- a/tests/control_plane/test_effect_runtime_integration.py +++ b/tests/control_plane/test_effect_runtime_integration.py @@ -1306,6 +1306,67 @@ def capture(stream): assert json.loads(lock_path.read_text()) == lock_owner +def test_an_envelope_published_before_the_deadline_is_still_read( + tmp_path: Path, + monkeypatch, +) -> None: + """A published envelope survives an exit that the parent's poll missed. + + The parent polls once more after the ready loop, but it uses that poll + only to decide whether to terminate the child and never reads the capture + again. An envelope the runtime had already published is therefore lost + whenever the exit lands between the parent's last in-loop poll and the + ready deadline. + """ + + runtime_dir = tmp_path / "runtime" + runtime_dir.mkdir() + fingerprint = "f" * 64 + info_path = runtime_dir / "runtime.json" + clock = {"monotonic": 0.0} + envelope = json.dumps({ + "schema_version": effect_runtime.EFFECT_RUNTIME_STARTUP_ERROR_SCHEMA_VERSION, + "code": "mutation_lock_timeout", + "message": "TypeScript Effect runtime could not publish its startup locator", + }).encode("utf-8") + + class _ExitingProcess: + def poll(self): + # The exit lands after the parent's last in-loop poll. + return 2 if clock["monotonic"] >= 1.0 else None + + def terminate(self) -> None: + raise AssertionError("an exited child must not be terminated") + + def sleep(seconds: float) -> None: + clock["monotonic"] += seconds + + monkeypatch.setattr(effect_runtime, "_read_info", lambda *_args, **_kwargs: None) + monkeypatch.setattr(effect_runtime, "_node_executable", lambda: "node") + monkeypatch.setattr( + effect_runtime.subprocess, + "Popen", + lambda *_args, **_kwargs: _ExitingProcess(), + ) + monkeypatch.setattr(effect_runtime, "_read_startup_stderr", lambda _stream: envelope) + monkeypatch.setattr(effect_runtime, "STARTUP_READY_TIMEOUT_SECONDS", 1.0) + monkeypatch.setattr(effect_runtime, "STARTUP_POLL_SECONDS", 0.5) + monkeypatch.setattr( + effect_runtime, + "time", + SimpleNamespace( + monotonic=lambda: clock["monotonic"], + sleep=sleep, + time=time.time, + ), + ) + + with pytest.raises(effect_runtime.EffectRuntimeStartupError) as raised: + effect_runtime._start_runtime(fingerprint=fingerprint, info_path=info_path) + + assert raised.value.diagnostic_code == "mutation_lock_timeout" + + def test_a_runtime_that_never_publishes_still_reports_a_bounded_timeout( tmp_path: Path, monkeypatch,