From d53156cdbf9a01b923cc24af8d1ef08ad73c02f9 Mon Sep 17 00:00:00 2001 From: bboonnee Date: Mon, 3 Aug 2026 13:28:29 +0800 Subject: [PATCH] U-038 fix: http_health polls for startup readiness instead of one-shot --- docs/development-plan.md | 1 + docs/sdd/unit_matrix.json | 2 +- supervisor/deploy_health_check.py | 60 +++++++++++++++++++++++++++++++++++++++++------------------- supervisor/test_deploy_health_check.py | 42 +++++++++++++++++++++++++++++++++++++++++- 4 files changed, 84 insertions(+), 21 deletions(-) diff --git a/docs/development-plan.md b/docs/development-plan.md index 7537576..0440ad1 100644 --- a/docs/development-plan.md +++ b/docs/development-plan.md @@ -375,6 +375,7 @@ PH2-S1/S2/S3/S4 之间除标注的依赖外相互独立，可并行推进。 - 依赖：U-037 - Done：三项检查全部通过 → `status=health_check_passed`；任一失败/超时 → `status=health_check_failed`，Live 全程未受影响（对应回滚路径 A） - **实现补充（2026-08-02）**：新增 `supervisor/deploy_health_check.py`。`process_alive` 复用 U-036 `deploy_supervisor.is_alive()`（`os.kill(pid,0)`），按 `HEALTH_CHECK_STARTUP_TIMEOUT` 轮询；`http_health` 请求候选的 `/api/health`——**这个端点 U-037 当时特意留空，这里补上**：`backend_server.py` 新增 `GET /api/health`，不只是"进程活着就 200"，还真的执行一次 `SELECT 1` 确认 sqlite 连接本身没卡死（连接卡死但进程还活着的场景，只测 `process_alive` 会漏检，这正是"health check"要抓的那类问题）；`canary_task` 是design doc §6"结果可预期的最小任务"字面实现——对候选发起一次真实的"建临时 project（临时目录 `git init` + 一个空提交）+ 建一个 goal 任务 + 读回确认 `status=queued`/`goal_text` 匹配"，不跑真实 Org Graph（不产生真实 `claude` 调用/花费），因为 `c_task_create` 本身落 `queued` 就是同步、确定性、"已知会通过"的最小验证，够用。三项检查按 03-C 原文"任一 fail 立即整体判定，不等其余项跑完"实现，`run_health_check()` 用 tuple-of-lambda 顺序短路，每项检查结果都真实写一条 `deploy_health_signal`（哪怕后续项因为短路没跑，已跑的那几条也留痕）。 + - **真实 bug（2026-08-03，U-042 第七/十一次真实压测都在这里失败）**：候选进程真实拉起后连续两次都在同一秒内卡在 `http_health` 检查——`process_alive` 已经判定"活着"，但 `urlopen` 立刻拿到 `Connection refused`。真实原因：`process_alive` 判定的是"进程存在"，不是"HTTP 服务已经真正绑定端口开始监听"——候选进程从 `Popen` 到 `backend_server.py` 完成 import、真正调用 `serve_forever()` 之间有一段真实存在的启动延迟，`check_http_health` 原来的实现是一次性 `urlopen(timeout=X)`，这个 `timeout` 只控制"连上之后等响应等多久"，对"端口压根还没开始监听"这种情况完全不起作用——`ECONNREFUSED` 是操作系统立刻拒绝的，不会等 timeout。这条修复本身涉及一处 03-C 明确写的设计决策（"不重试——重试属于给坏版本第二次机会"），**没有直接动手改，先跟用户确认了这算不算违反那条策略**：结论是"容忍启动延迟"和"给一个已经失败的检查第二次机会"是两回事——`check_process_alive` 自己早就在做前者（轮询到 30s 上限），只是 `http_health` 没跟上同一个模式而已；一次真实的非 2xx 响应仍然是"服务已经起来但判定为不健康"，依旧立刻失败不重试，这条界线没有被打破。`check_http_health` 现在改成和 `check_process_alive` 一样在自己的 timeout 窗口内轮询，只对连接类错误（`URLError`/`OSError`，即"还没开始监听"）重试，真实收到的非 2xx 响应仍然立即失败。补了两个真实回归测试：`test_connection_refused_polls_until_server_actually_listening`（真实起一个延迟 0.3 秒才开始监听的服务器，验证轮询最终能等到它）、`test_real_http_error_response_fails_immediately_without_polling`（确认真实的 500 响应不会被误当成"还没起来"而重试）。 - 覆盖：03-C `c_deploy_supervisor_health_check`；`backend_server.py` 新增 `GET /api/health`（U-037 留空的口子，这里补上）；01-M `deploy_health_signal`（首次被真正写入） - **U-039 [Risk Gate]** `c_deploy_supervisor_cutover`：蓝绿切换本体（Live 停止接受新触发 → 候选切换到生产端口/生产库 → 旧 Live checkout 保留为 `previous_instance_dir`） diff --git a/docs/sdd/unit_matrix.json b/docs/sdd/unit_matrix.json index d72105c..8a2d692 100644 --- a/docs/sdd/unit_matrix.json +++ b/docs/sdd/unit_matrix.json @@ -55,7 +55,7 @@ {"id": "U-035", "phase": "PH5", "sub_phase": "PH5-S1", "name": "self-target worktree 无条件强制 + core_engine 分类审计（见 development-plan.md 2026-08-02 实现补充）", "classification": "Risk Gate", "depends_on": ["U-013", "U-016", "U-034"], "coverage": {"model": [], "view": [], "controller": [], "process": [], "requirement": ["REQ-03"]}, "done": "self-target 时无条件走 worktree（work_graph_orchestrate.run_graph 内强制）；core_engine 分类（src/core_engine_classify.py，路径规则）在 self-target 任务 PASS 收尾时记一条审计用 bug_record；且改动落地后重跑 U-013/REQ-03（worktree 隔离）现有回归用例全部通过。**2026-08-02 用户决策修正**：Deploy Supervisor 触发条件按 supervisor-auto-rollback-design.md §1 字面设计（self-target+PASS 即触发，bug_record 是旁路产物不是前提），而非 03-C/04-P 字面文本要求的\"先有 core_engine bug_record\"——后者会让从不产生 bug_record 的 goal 型自我改进任务永远触发不了 Deploy Supervisor，已用 AskUserQuestion 与用户确认此订正。c_org_loop_route 未改动（fast_lane/full_replan 是 FAIL 路径重试路由，与此处 PASS 路径的蓝绿触发正交），deployment 行创建仍是 U-037 的范围，不在本 Unit 提前做"}, {"id": "U-036", "phase": "PH5", "sub_phase": "PH5-S2", "name": "supervisor/isolation 补齐单测 + Deploy Supervisor 进程骨架（见 development-plan.md 2026-08-02 实现补充）", "classification": "Enabler", "depends_on": [], "coverage": {"model": [], "view": [], "controller": [], "process": [], "requirement": []}, "done": "四模块各有 test_*.py（供 python3 -m unittest discover -s supervisor/isolation 运行，52 测试全绿）；Deploy Supervisor 骨架（supervisor/deploy_supervisor.py）独立进程可启停（真实子进程验证，非 mock），不受 Live/Candidate 崩溃影响；本 Unit 只做进程生命周期骨架，不含任何真实部署决策逻辑（U-037+ 的 poll_fn 挂载点）"}, {"id": "U-037", "phase": "PH5", "sub_phase": "PH5-S2", "name": "c_deploy_supervisor_stage（见 development-plan.md 2026-08-02/03 实现补充）", "classification": "Risk Gate", "depends_on": ["U-034", "U-036"], "coverage": {"model": ["deployment"], "view": [], "controller": ["c_deploy_supervisor_stage"], "process": [], "requirement": []}, "done": "能生成 deployment 记录并拉起监听临时端口、连一次性 DB 副本的候选进程（supervisor/deploy_stage.py，真实 git worktree + 真实子进程验证过）；顺带补上 deployment.candidate_instance_dir 缺字段 + backend_server.py 首个 CLI 入口。2026-08-03：U-042 第三次真实自举压测发现 _copy_prod_db() 没有处理 prod_db_path 首次不存在的引导期场景（真实 FileNotFoundError），已修复为自动新建带 schema 的空库并补测试"}, - {"id": "U-038", "phase": "PH5", "sub_phase": "PH5-S2", "name": "c_deploy_supervisor_health_check（见 development-plan.md 2026-08-02 实现补充）", "classification": "Risk Gate", "depends_on": ["U-037"], "coverage": {"model": ["deploy_health_signal"], "view": [], "controller": ["c_deploy_supervisor_health_check"], "process": [], "requirement": []}, "done": "process_alive/http_health/canary_task 三项检查全过 -> health_check_passed；任一失败 -> health_check_failed 且 Live 未受影响（supervisor/deploy_health_check.py，真实 HTTP+真实 project/task 创建验证过）；backend_server.py 新增 GET /api/health（真查一次 SELECT 1，不只是进程存活）"}, + {"id": "U-038", "phase": "PH5", "sub_phase": "PH5-S2", "name": "c_deploy_supervisor_health_check（见 development-plan.md 2026-08-02/03 实现补充）", "classification": "Risk Gate", "depends_on": ["U-037"], "coverage": {"model": ["deploy_health_signal"], "view": [], "controller": ["c_deploy_supervisor_health_check"], "process": [], "requirement": []}, "done": "process_alive/http_health/canary_task 三项检查全过 -> health_check_passed；任一失败 -> health_check_failed 且 Live 未受影响（supervisor/deploy_health_check.py，真实 HTTP+真实 project/task 创建验证过）；backend_server.py 新增 GET /api/health（真查一次 SELECT 1，不只是进程存活）。2026-08-03：U-042 第七/十一次真实压测均卡在 http_health（进程已存活但端口还没真正开始监听，ECONNREFUSED 立即触发、原实现单次尝试不重试），已跟用户确认不违反 03-C\"不重试\"策略后，改成和 process_alive 一样轮询等待端口就绪，真实非 2xx 响应仍立即失败"}, {"id": "U-039", "phase": "PH5", "sub_phase": "PH5-S2", "name": "c_deploy_supervisor_cutover（见 development-plan.md 2026-08-02 实现补充）", "classification": "Risk Gate", "depends_on": ["U-038"], "coverage": {"model": ["deployment"], "view": [], "controller": ["c_deploy_supervisor_cutover"], "process": [], "requirement": []}, "done": "健康检查通过后完成真实切换（supervisor/deploy_cutover.py，真实进程停止+重启验证过）；在途 work_node_execution 重启后可恢复（复用既有 REQ-06 机制）；previous_instance_dir 保留至监控窗口结束；新增 LIVE_PORT=8420 常量（05 §5.9 缺的一个字段）；真实测试发现并修复 deploy_supervisor.is_alive() 的僵尸进程判活缺陷（新增 reap_if_exited()）"}, {"id": "U-040", "phase": "PH5", "sub_phase": "PH5-S3", "name": "c_deploy_supervisor_monitor（见 development-plan.md 2026-08-02 实现补充）", "classification": "Risk Gate", "depends_on": ["U-039"], "coverage": {"model": ["deploy_health_signal"], "view": [], "controller": ["c_deploy_supervisor_monitor"], "process": [], "requirement": []}, "done": "四类信号采样正常（supervisor/deploy_monitor.py）；validator_approval_rate 偏离基线阈值时触发 anomaly_detected；approve 占比算法基于对 scheduler.finish_task_lifecycle 真实代码逻辑的核实（PASS 从不产生 bug_record，FAIL 必然产生），非字面 SDD 定义"}, {"id": "U-041", "phase": "PH5", "sub_phase": "PH5-S3", "name": "c_deploy_supervisor_rollback（见 development-plan.md 2026-08-02/03 实现补充）", "classification": "Risk Gate", "depends_on": ["U-038", "U-040"], "coverage": {"model": ["deployment"], "view": [], "controller": ["c_deploy_supervisor_rollback"], "process": [], "requirement": []}, "done": "回滚路径 A/B 各跑通一次（supervisor/deploy_rollback.py，真实进程+真实 git 仓库验证）；旧版本也起不来时正确终态到 blocked_pending_human（真实场景验证，非假设）；git revert 冲突有明确处理（真实构造冲突历史验证过，含 --abort 清理）。2026-08-03：U-042 第七次真实压测第一次真正走到 health_check 环节，发现 rollback_path_a 从未清理候选的 git worktree 检出目录（永久留在磁盘+git worktree list），已修复并补真实回归测试"}, diff --git a/supervisor/deploy_health_check.py b/supervisor/deploy_health_check.py index aeeb449..bd1bc11 100644 --- a/supervisor/deploy_health_check.py +++ b/supervisor/deploy_health_check.py @@ -47,24 +47,46 @@ def check_process_alive(pid, timeout=HEALTH_CHECK_STARTUP_TIMEOUT, sleep=time.sl } -def check_http_health(port, timeout=HEALTH_CHECK_HTTP_TIMEOUT): - try: - with urllib.request.urlopen("http://127.0.0.1:{}/api/health".format(port), timeout=timeout) as resp: - if resp.status == 200: - return {"signal_type": "http_health", "status": "ok", "detail": None} - return { - "signal_type": "http_health", "status": "fail", - "detail": "unexpected HTTP status {}".format(resp.status), - } - except urllib.error.HTTPError as e: - # HTTPError IS the response object (a non-2xx status raises rather - # than returning) -- close it explicitly, `except` doesn't run our - # `with` block's __exit__ for us. - detail = "unexpected HTTP status {}".format(e.code) - e.close() - return {"signal_type": "http_health", "status": "fail", "detail": detail} - except (urllib.error.URLError, OSError) as e: - return {"signal_type": "http_health", "status": "fail", "detail": str(e)} +def check_http_health(port, timeout=HEALTH_CHECK_HTTP_TIMEOUT, sleep=time.sleep, now=time.time): + """Polls until `timeout` elapses, same as `check_process_alive` -- + NOT the "重试属于给坏版本第二次机会" policy this module's own docstring + warns against (real self-hosting runs, 2026-08-03, hit this: `pid` + reads alive within milliseconds of `Popen`, well before the candidate + process has finished importing modules and actually bound its listen + socket -- `urlopen` on a port nothing is listening on yet raises + ECONNREFUSED essentially instantly, `timeout=` only bounds how long to + wait for a RESPONSE once connected, not how long to wait for the port + to start accepting connections at all). `check_process_alive` already + established the precedent that tolerating normal startup latency + within ONE health-check pass isn't "retrying a failed check" -- this + just extends the same tolerance to the next check in the same pass. + A genuine non-2xx HTTP response IS a definitive answer from a server + that's actually up, so that still fails immediately without polling, + preserving the real "don't give a bad build a second chance" intent. + """ + deadline = now() + timeout + last_detail = None + while now() < deadline: + try: + with urllib.request.urlopen("http://127.0.0.1:{}/api/health".format(port), timeout=1) as resp: + if resp.status == 200: + return {"signal_type": "http_health", "status": "ok", "detail": None} + return { + "signal_type": "http_health", "status": "fail", + "detail": "unexpected HTTP status {}".format(resp.status), + } + except urllib.error.HTTPError as e: + # HTTPError IS the response object (a non-2xx status raises rather + # than returning) -- close it explicitly, `except` doesn't run our + # `with` block's __exit__ for us. A real response from a live + # server, not a startup race -- fail immediately, no polling. + detail = "unexpected HTTP status {}".format(e.code) + e.close() + return {"signal_type": "http_health", "status": "fail", "detail": detail} + except (urllib.error.URLError, OSError) as e: + last_detail = str(e) + sleep(0.5) + return {"signal_type": "http_health", "status": "fail", "detail": last_detail} def _post_json(port, path, payload, timeout): @@ -154,7 +176,7 @@ def run_health_check( signals = [] checks = ( lambda: check_process_alive(pid, timeout=startup_timeout, sleep=sleep, now=now), - lambda: check_http_health(port, timeout=http_timeout), + lambda: check_http_health(port, timeout=http_timeout, sleep=sleep, now=now), lambda: check_canary_task(port, timeout=canary_timeout), ) for check in checks: diff --git a/supervisor/test_deploy_health_check.py b/supervisor/test_deploy_health_check.py index eb4026c..6164bec 100644 --- a/supervisor/test_deploy_health_check.py +++ b/supervisor/test_deploy_health_check.py @@ -74,8 +74,48 @@ class CheckHttpHealthTest(RealServerTestBase): self.assertEqual(signal["status"], "fail") def test_nothing_listening_on_port_returns_fail(self): - signal = dhc.check_http_health(1) # privileged/unbound port, nothing listening + clock = {"t": 0.0} + signal = dhc.check_http_health( + 1, timeout=5, # privileged/unbound port, nothing listening + sleep=lambda s: clock.__setitem__("t", clock["t"] + s), now=lambda: clock["t"], + ) + self.assertEqual(signal["status"], "fail") + + def test_connection_refused_polls_until_server_actually_listening(self): + # 2026-08-03 regression: a real self-hosting run showed + # process_alive can read 'ok' before the candidate has finished + # binding its listen socket -- check_http_health must tolerate + # that same startup window instead of failing on the first + # ECONNREFUSED, same as check_process_alive already tolerates a + # not-yet-existing pid. + server = backend_server.create_server(db_path=":memory:") + real_port = server.server_address[1] + self.addCleanup(server.server_close) + + def start_server_after_delay(): + thread = threading.Thread(target=server.serve_forever, daemon=True) + thread.start() + self.addCleanup(lambda: (server.shutdown(), thread.join(timeout=5))) + + timer = threading.Timer(0.3, start_server_after_delay) + timer.start() + self.addCleanup(timer.cancel) + + signal = dhc.check_http_health(real_port, timeout=5) + self.assertEqual(signal, {"signal_type": "http_health", "status": "ok", "detail": None}) + + def test_real_http_error_response_fails_immediately_without_polling(self): + # a genuine non-2xx response IS a definitive answer from a live + # server -- must not be treated the same as "not up yet". + sleeps = [] + with patch.object(dhc.urllib.request, "urlopen") as mock_urlopen: + error = dhc.urllib.error.HTTPError("url", 500, "Internal Server Error", {}, None) + mock_urlopen.side_effect = error + signal = dhc.check_http_health(self.port, timeout=5, sleep=lambda s: sleeps.append(s), now=lambda: 0.0) self.assertEqual(signal["status"], "fail") + self.assertIn("500", signal["detail"]) + self.assertEqual(sleeps, []) + mock_urlopen.assert_called_once() class CheckCanaryTaskTest(RealServerTestBase): -- libgit2 0.21.4