Commit 55a9c0b5f47a20a949e222011a15bd12a1ab60d8
1 parent
fa86f363
I: production task reconciliation loop (FR-2)
Recovers tasks abandoned mid-flight (status in queued/planning_brd_prd_sdd/ coding/validating with no recent execution_event) by re-driving them through task_execution.run_or_resume_task_lifecycle on a background poll, guarded by an in-process in-flight lock to avoid double dispatch. Responds to a real 2026-08-06 incident where a task sat stuck in 'validating' for 15+ hours with nothing polling it. Scoped to FR-2 only from docs/todo/scheduler-production-polling-loop- requirements.md; FR-1 (new-goal auto-dispatch) stays out per that doc's own non-goals -- it's a separate, larger autonomy-boundary decision. Design recorded in docs/todo/scheduler-production-polling-loop-design.md. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Showing
7 changed files
with
667 additions
and
11 deletions
docs/todo/scheduler-production-polling-loop-design.md
0 → 100644
| 1 | +# 生产环境调度/复原循环——详细设计(FR-2 部分) | |
| 2 | + | |
| 3 | +**日期**: 2026-08-06 | |
| 4 | +**性质**: SDD 层面设计文档,对应 `scheduler-production-polling-loop-requirements.md`。 | |
| 5 | +**范围**: 只覆盖该需求文档的 FR-2(在途任务复原)。FR-1(新 Goal 自动派发)按需求文档自身的 | |
| 6 | +非目标 #1 和风险章节,仍然是一个未决的、需要单独确认的自主权边界决策,本文档不涉及,需求文档 | |
| 7 | +本身也因此暂不移入 `docs/done/`。 | |
| 8 | +**状态**: 已实现(`src/task_reconciliation.py` + `src/backend_server.py::_start_reconciliation_loop` | |
| 9 | ++ `src/task_execution.py` 的 in-flight 互斥锁),本文档是对已落地实现的设计记录,补齐 | |
| 10 | +`docs/todo/` 两段式流程里"确认后产出 SDD 设计文档"这一步。 | |
| 11 | + | |
| 12 | +## 1. 整体方案 | |
| 13 | + | |
| 14 | +拆成三层,分别对应需求文档 §8 的五个开放问题: | |
| 15 | + | |
| 16 | +1. **候选发现**(`task_reconciliation.find_stale_resumable_tasks`):只读查询,扫描 | |
| 17 | + `task.status IN task_execution._RESUMABLE_STATUSES` 且"最近一次活动早于阈值"的任务。 | |
| 18 | +2. **一次调度扫描**(`task_reconciliation.reconcile_once`):调用发现函数,对每个候选调用 | |
| 19 | + `task_execution.start_task_execution_in_background`,单个候选派发失败不影响其余候选 | |
| 20 | + (复用 04-P "调度器继续执行队列中其他任务" 的既有原则)。 | |
| 21 | +3. **载体**(`backend_server.py::_start_reconciliation_loop`):`main()` 专属的后台线程, | |
| 22 | + `while True: reconcile_once(); sleep(interval)`,`--reconciliation-interval-seconds` | |
| 23 | + (默认 300s)/`--disable-reconciliation-loop` 两个 CLI 开关。 | |
| 24 | + | |
| 25 | +## 2. 开放问题回答 | |
| 26 | + | |
| 27 | +| 需求文档 §8 的问题 | 本设计的答案 | | |
| 28 | +|---|---| | |
| 29 | +| FR-2 轮询周期 | 300s(`_DEFAULT_RECONCILIATION_INTERVAL_SECONDS`),可通过 `--reconciliation-interval-seconds` 覆盖 | | |
| 30 | +| "一段时间没有新进展"的判定信号与阈值 | 用 `execution_event` 该 task 最近一条记录的 `created_at`(无记录则退回 `task.created_at`),**不用** `task.updated_at`——阶段执行期间 `task.updated_at` 本来就不变,这正是这次事故排查时的真实盲点。阈值统一 1800s,不区分阶段(见下方"已知简化") | | |
| 31 | +| FR-2 载体形式 | `backend_server.py::main()` 内置守护线程,不是独立进程。理由:FR-2 只是"帮已存在的任务把该调用的函数再调用一次",复用的是 `task_execution` 现有的进程内 in-flight 互斥锁,做成独立进程反而需要额外的跨进程协调;这与 Deploy Supervisor"独立进程、无共享失败域"哲学的适用场景不同——Deploy Supervisor 独立是因为它需要在 `backend_server` 本身挂掉时还能做健康检查/回滚,FR-2 不需要这个属性 | | |
| 32 | +| FR-2 互斥机制 | 进程内 `threading.Lock` + `set`(`task_execution._in_flight_task_ids`),不是数据库锁。有意选择:只需要防止**同一进程内**两个线程(控制台点 Start 的线程 vs 本循环)竞争同一个 `task_id`;不需要跨进程/跨重启存活——重启后这个 set 清空为空集合本身就是正确状态(意味着"这个进程里没有任何东西正在跑"),不是 bug | | |
| 33 | +| 是否暴露为可配置项 | 是:`--reconciliation-interval-seconds`、`--disable-reconciliation-loop`。硬编码的是阈值本身(`_DEFAULT_STALE_AFTER_SECONDS=1800`),未暴露成 CLI 参数——v1 先用一个保守默认值,符合需求文档非目标 #4 | | |
| 34 | + | |
| 35 | +## 3. 竞态处理 | |
| 36 | + | |
| 37 | +`find_stale_resumable_tasks` 在扫描时检查 `is_in_flight()`,但扫描到派发之间存在窗口——这段 | |
| 38 | +时间里同一个 `task_id` 可能被控制台"Start"按钮抢先派发。这不是需要额外加锁解决的问题: | |
| 39 | +`start_task_execution_in_background` 内部的 `_try_claim` 本身是原子的(持锁检查+插入), | |
| 40 | +竞态发生时后到者会直接收到 `TaskExecutionError`,`reconcile_once` 捕获后跳过该候选、不影响 | |
| 41 | +其余候选——测试 `test_one_dispatch_failure_does_not_block_others` 覆盖了这条路径。 | |
| 42 | + | |
| 43 | +## 4. 已知简化(v1 天花板,非 bug) | |
| 44 | + | |
| 45 | +- **单一全局阈值,不分阶段**。需求文档 §8 提到"Coder 阶段可能比 Validator 阶段容忍更长空闲", | |
| 46 | + v1 用统一的 1800s(比最长单次阻塞调用 Validator 自身 Work Graph 的 `timeout=1200s` 多 | |
| 47 | + 600s 余量)。升级路径:给 `_RESUMABLE_STATUSES` 里每个状态配一个独立阈值,按 | |
| 48 | + `task.assigned_org_node`/`task.status` 查表。 | |
| 49 | +- **候选扫描全表查询,无索引优化**。当前任务量级下(个位数到几十个并发 task)不是问题; | |
| 50 | + 升级路径:如果任务量上升,给 `task.status`、`execution_event.task_id` 加索引。 | |
| 51 | + | |
| 52 | +## 5. 可观测性修复(本次评审新增,2026-08-06) | |
| 53 | + | |
| 54 | +原实现里 `_start_reconciliation_loop` 的 `except Exception: pass` 会让"每一轮都失败"和 | |
| 55 | +"每一轮都没有候选"从外部看起来完全一样——对一个设计目标就是无人值守 7x24 运行的循环来说, | |
| 56 | +这种静默失败是最危险的一类。已改为 `traceback.print_exc()`,异常信息进 stderr(`main()` | |
| 57 | +是真实 CLI 入口,stderr 在部署环境下通常会被进程管理器捕获落盘)。这不引入新依赖,也不改变 | |
| 58 | +"一次失败不杀死循环"的既有语义。 | |
| 59 | + | |
| 60 | +## 6. 验收标准核对(对照需求文档 §5) | |
| 61 | + | |
| 62 | +1. ✅ `test_finds_task_with_no_activity_at_all` / `test_stale_event_still_flagged` 覆盖"卡住的 | |
| 63 | + 任务被重新捡起" | |
| 64 | +2. ✅ `test_excludes_task_with_recent_event` / `test_uses_most_recent_event_not_earliest` 覆盖 | |
| 65 | + "正常在跑的任务不会被误判"——但这两个测试验证的是"有新鲜 `execution_event`"这一路径,没有 | |
| 66 | + 单独构造"一次长达接近 1200s 的阻塞调用期间完全没有任何新事件"的场景。这属于用阈值余量 | |
| 67 | + (1800 vs 1200)做保证、而非用事件覆盖做保证,测试没有专门验证这条时间余量假设本身——留作 | |
| 68 | + 后续如果要收紧阈值时的一个真实回归风险点。 | |
| 69 | +3. FR-1(新建 `queued` Goal 自动派发)不适用——本设计明确不覆盖 FR-1。 | |
| 70 | +4. ✅ `--disable-reconciliation-loop` 提供独立开关;FR-2 与 FR-1 天然独立(FR-1 尚未实现, | |
| 71 | + 两者不存在耦合)。 | |
| 72 | + | |
| 73 | +## 7. 后续(不在本次范围内) | |
| 74 | + | |
| 75 | +FR-1(新 Goal 自动派发)仍然是需求文档标注的"改变系统自主权边界"的决策,按该文档非目标 #1 | |
| 76 | +的要求,需要单独确认是否要做、什么时候做,不与 FR-2 混跑。在那之前,`queued` 状态的新 Goal | |
| 77 | +仍然需要人工触发 `run_goal_to_completion`/`scheduler.run_scheduler_once()`。 | ... | ... |
docs/todo/scheduler-production-polling-loop-requirements.md
0 → 100644
| 1 | +# 生产环境调度/复原循环——需求文档 | |
| 2 | + | |
| 3 | +**日期**: 2026-08-06 | |
| 4 | +**性质**: 需求文档(BRD/PRD 层面),不含详细技术设计。回应一次真实事故的根因排查——任务 `3605272e-fe33-48cc-b3f3-e0c0ba26f970` 在 `validating` 状态卡死 15+ 小时,`execution_event` 表在此期间零记录,`work_graph_run` 里从未出现 Validator 的运行记录。 | |
| 5 | +**状态**: 草案,待评审。 | |
| 6 | + | |
| 7 | +## 1. 背景 | |
| 8 | + | |
| 9 | +排查这次真实事故发现两层原因: | |
| 10 | + | |
| 11 | +1. **生产后端进程从来没有接入过任何轮询循环**。`docs/implementation-gap-analysis.md` 第 6 条早就记录了这个缺口:"给某个常驻进程(`backend_server.py` 或独立进程)接入 `scheduler.run_scheduler_once()` 的轮询循环",评级"高",并且明确建议"改变系统自己的自主权边界,建议单独一批、额外人工审查 diff,不要和其他 gap 混跑"。这次事故是这条缺口第一次以真实用户可见的方式发作。 | |
| 12 | +2. **即使真的接上 `scheduler.run_scheduler_once()`,也不会自动修好这次事故这类问题**——这是排查过程中新发现的、比原缺口描述更精确的一点。`run_scheduler_once(db_path, goals, max_workers=None)` 的入参 `goals` 是 `[(target_folder_path, goal_text), ...]`,语义是"这一轮要**新建**并跑完这些 Goal",内部通过 `task_create.create_task()` 每次都新建一个 `task` 行。它解决的是"新 Goal 怎么被自动拿去跑",**不是**"一个已经存在、卡在某个中间状态的 `task_id` 怎么被自动接回去继续跑"——后者需要的是 `task_execution.run_or_resume_task_lifecycle`(按 `task_id` 恢复),是完全不同的另一个函数、另一条代码路径。这次事故属于第二类:任务本身已经存在、状态是 `validating`(`task_execution._RESUMABLE_STATUSES` 里合法的可恢复状态之一),只是没有任何东西在合适的时机去调用恢复逻辑。 | |
| 13 | + | |
| 14 | +这次事故本身的具体触发点(`validating` 状态本来就无法通过 `run_or_resume_task_lifecycle` 恢复)已经单独修复(见 `src/task_execution.py` 的 `_RESUMABLE_STATUSES`/`request_pause` 改动,2026-08-06)——这是"人工点 Resume 现在能生效了",不等于"以后不会再有任务卡死没人管"。本需求要解决的是后者。 | |
| 15 | + | |
| 16 | +## 2. 目标 | |
| 17 | + | |
| 18 | +把生产环境需要的"持续推进任务"能力,拆成两个明确区分、可以分开排期的子问题: | |
| 19 | + | |
| 20 | +1. **新 Goal 派发**:`queued` 状态的任务(或者说,还没被任何调用触发过 `run_goal_to_completion`/`run_or_resume_task_lifecycle` 的新 Goal)需要被自动拿去执行,不需要人工每次手动点 Start。 | |
| 21 | +2. **在途任务复原(这次事故的真正根因)**:任何已经开始执行、但因为驱动它的那次调用提前退出(进程重启、脚本运行完毕、连接断开等任何原因)而卡在某个可恢复中间状态(`task_execution._RESUMABLE_STATUSES`:`queued`/`planning_brd_prd_sdd`/`coding`/`validating`)、且已经**一段时间没有新进展**的任务,需要被自动重新接回去继续跑,而不是无限期地停在原地、既不算 `blocked_pending_human`(触发不了人工介入通知),也没有任何东西在真的干活。 | |
| 22 | + | |
| 23 | +## 3. 非目标 | |
| 24 | + | |
| 25 | +1. **不在本文档里裁定"要不要做""什么时候做"这个更大的问题**。`docs/implementation-gap-analysis.md` 已经把这条标注为"改变系统自己的自主权边界"——是否现在就投入、要不要额外的人工评审门槛,是需要单独确认的决策,本文档只负责把需求本身讲清楚,供决策时参考。 | |
| 26 | +2. **不要求解决方案是常驻进程/独立进程/`backend_server.py` 内置线程三选一中的哪一个**。具体载体形式留给设计阶段,本文档只描述行为需求。 | |
| 27 | +3. **不重新设计 `run_scheduler_once`/`run_goal_to_completion`/`run_or_resume_task_lifecycle` 这三个已经存在且经过测试的函数本身**。它们的行为已经是对的,本需求要解决的是"谁、在什么时机去调用它们"这一层,不是重写它们的内部逻辑。 | |
| 28 | +4. **不要求第一版就有一套精细的"任务卡死"判定算法**(比如区分"真的卡死"和"合理地在等真实的 `claude -p` 长耗时调用")。第一版可以用一个保守、简单的阈值(比如"`updated_at`/最近一条 `execution_event` 距今超过 N 分钟,且没有已知的进行中标记"),不需要一次做到完美。 | |
| 29 | + | |
| 30 | +## 4. 功能需求 | |
| 31 | + | |
| 32 | +| # | 需求描述 | 优先级 | | |
| 33 | +|---|---|---| | |
| 34 | +| FR-1 | 需要一个机制,定期(具体周期留待设计阶段)调用 `scheduler.run_scheduler_once()` 派发新 Goal——对应「目标 1」。 | 必须 | | |
| 35 | +| FR-2 | 需要一个独立的机制,定期扫描 `task` 表里状态属于 `task_execution._RESUMABLE_STATUSES` 且"已经一段时间没有新进展"的任务,对每一个调用 `task_execution.run_or_resume_task_lifecycle`(或 `start_task_execution_in_background`)——对应「目标 2」,是这次事故的直接对应修复。 | 必须 | | |
| 36 | +| FR-3 | FR-2 的"已经一段时间没有新进展"判定,需要能区分"真的没人管"和"确实在真实执行中,只是这一步本来就耗时"——不能简单靠 `task.status` 停留时间判断(比如 Validator 自己的 Work Graph 跑一次可能就要接近 `timeout=1200` 秒),需要参考更细粒度的信号(比如该任务关联的 `work_node_execution`/`execution_event` 最近一次活动时间,而不是 `task.updated_at`——`task.updated_at` 在阶段内部执行期间根本不会变,这正是这次事故排查时的真实盲点)。 | 必须 | | |
| 37 | +| FR-4 | FR-1、FR-2 两个机制必须能独立开关/独立排期——不能因为"要接 FR-1 需要走完整的人工评审流程"就连带阻塞了 FR-2(这次事故的直接修复)。 | 必须 | | |
| 38 | +| FR-5 | 无论 FR-1/FR-2 最终选择常驻进程还是独立进程实现,都不能引入新的"共享一个 sqlite 连接跨线程"风险——复用 `scheduler.py` 模块文档里已经验证过的模式(每个 worker 各自开自己的连接 + `busy_timeout`),不要重新踩 U-027 已经用真实 SIGSEGV 验证过的坑。 | 必须 | | |
| 39 | + | |
| 40 | +## 5. 验收标准 | |
| 41 | + | |
| 42 | +1. 人为构造一个"任务卡在 `validating`,很久没有新进展"的场景(复现这次事故的条件),验证 FR-2 的机制能在设定的检测周期内把它重新接回去执行,不需要人工干预。 | |
| 43 | +2. 人为构造一个"任务正常在跑,Validator 的 Work Graph 正在执行中,还没超过合理耗时"的场景,验证 FR-2 的机制**不会**误判成"卡死"、不会对一个正常在跑的任务重复触发 `run_or_resume_task_lifecycle`(这会导致同一个任务被并发跑两次,需要明确防止)。 | |
| 44 | +3. 新建一个 `queued` 状态的 Goal,不手动点 Start,验证 FR-1 的机制能在设定周期内自动派发执行。 | |
| 45 | +4. FR-1 和 FR-2 分别单独关闭时,各自的行为符合预期(关 FR-1 不影响 FR-2 正常工作,反之亦然)。 | |
| 46 | + | |
| 47 | +## 6. 约束与假设 | |
| 48 | + | |
| 49 | +- 复用现有的 `task_execution._RESUMABLE_STATUSES`(已扩展为包含 `validating`)作为 FR-2 判断"这个任务原则上可以恢复"的依据,不重新定义一套判断标准。 | |
| 50 | +- FR-2 的具体实现要避免和「人工点 Resume」竞争——如果一个任务已经在被 `start_task_execution_in_background` 的某个后台线程处理,FR-2 的扫描不能对同一个 `task_id` 重复触发第二次执行。具体的互斥机制(数据库标记、内存锁、还是别的方式)留给设计阶段。 | |
| 51 | + | |
| 52 | +## 7. 风险 | |
| 53 | + | |
| 54 | +- **FR-1(新 Goal 自动派发)是这次事故排查之前就已经被 `implementation-gap-analysis.md` 标注为"改变系统自主权边界"的决策**,本文档不试图淡化这一点——它意味着系统会在没有人显式点击"Start"的情况下自主开始消耗真实 API 调用、真实修改代码。这条风险原样保留,需要在决策阶段被认真对待。 | |
| 55 | +- **FR-2(在途任务复原)看起来风险更小(只是让已经存在的任务继续跑完,不是凭空发起新工作),但仍然是自主行为的扩展**——需要在设计阶段想清楚"防误判"(FR-3/验收标准 2)没做好的后果:一个只是耗时较长、并没有真的卡死的任务被提前打断重跑,可能造成重复的 API 花费或者更糟的状态不一致。 | |
| 56 | +- **两个机制如果实现成同一个循环、共享同一套判断逻辑,容易在后续维护中被混为一谈**——按第 2 节"目标"明确拆开成两个独立问题,是为了避免这种混淆,设计阶段应该保持这个拆分,不要图省事合并成一个"万能调度循环"。 | |
| 57 | + | |
| 58 | +## 8. 开放问题(留给详细设计阶段回答) | |
| 59 | + | |
| 60 | +- [ ] FR-1/FR-2 各自的轮询周期定多少。 | |
| 61 | +- [ ] FR-3"已经一段时间没有新进展"的具体判定信号和阈值——参考哪张表的哪个时间戳字段,阈值怎么定(是否要按 `task` 当前所处的具体阶段给不同阈值,比如 Coder 阶段允许的空闲时间可能比 Validator 阶段更长)。 | |
| 62 | +- [ ] FR-1/FR-2 的载体形式:`backend_server.py` 内置后台线程,还是独立进程(类似 Deploy Supervisor 的"独立进程、无共享失败域"哲学)。 | |
| 63 | +- [ ] FR-2 的互斥机制具体怎么实现,防止同一个任务被并发重复触发。 | |
| 64 | +- [ ] 这两个机制要不要暴露成可配置项(管理后台开关/环境变量),还是先硬编码一个保守的默认行为。 | ... | ... |
src/backend_server.py
| ... | ... | @@ -33,14 +33,16 @@ import socket |
| 33 | 33 | import sqlite3 |
| 34 | 34 | import subprocess |
| 35 | 35 | import threading |
| 36 | +import time | |
| 37 | +import traceback | |
| 36 | 38 | import urllib.parse |
| 37 | 39 | from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer |
| 38 | 40 | |
| 39 | 41 | from src import ( |
| 40 | 42 | artifact_query, budget_guardrail, bug_record, deployment_query, execution_log, |
| 41 | 43 | org_loop_route, paths, project_query, project_scaffold, schema, settings_config, |
| 42 | - skill_query, skill_update, task_create, task_execution, task_query, work_graph_fork, | |
| 43 | - work_graph_run_query, ws_subscribe, | |
| 44 | + skill_query, skill_update, task_create, task_execution, task_query, task_reconciliation, | |
| 45 | + work_graph_fork, work_graph_run_query, ws_subscribe, | |
| 44 | 46 | ) |
| 45 | 47 | |
| 46 | 48 | _FRONTEND_DIR = os.path.join(os.path.dirname(os.path.dirname(os.path.abspath(__file__))), "frontend") |
| ... | ... | @@ -1042,6 +1044,42 @@ def create_server(host="127.0.0.1", port=0, db_path=None, skill_repo_path=None): |
| 1042 | 1044 | return server |
| 1043 | 1045 | |
| 1044 | 1046 | |
| 1047 | +_DEFAULT_RECONCILIATION_INTERVAL_SECONDS = 300 | |
| 1048 | + | |
| 1049 | + | |
| 1050 | +def _start_reconciliation_loop(db_path, interval_seconds): | |
| 1051 | + """2026-08-06 (FR-2 of docs/todo/scheduler-production-polling-loop- | |
| 1052 | + requirements.md): background daemon thread that repeatedly calls | |
| 1053 | + `task_reconciliation.reconcile_once()`. Deliberately started here, NOT | |
| 1054 | + inside `create_server()` -- that function is instantiated fresh by | |
| 1055 | + nearly every backend_server test, and a background loop dispatching | |
| 1056 | + real `start_task_execution_in_background()` calls (real subprocess | |
| 1057 | + invocations) during unit tests would be exactly the kind of test | |
| 1058 | + pollution CLAUDE.md's Testing constraint exists to prevent. Only | |
| 1059 | + `main()` (the real CLI entry point) starts this. | |
| 1060 | + | |
| 1061 | + Runs one pass immediately (a restart is exactly when previously- | |
| 1062 | + abandoned tasks most need to be picked back up, not `interval_seconds` | |
| 1063 | + later), then repeats. A bad pass never kills the loop -- the next | |
| 1064 | + scheduled pass just tries again, same "one failure doesn't stop | |
| 1065 | + everything else" principle `reconcile_once()` itself already applies | |
| 1066 | + per-candidate. The traceback still goes to stderr: a silently-swallowed | |
| 1067 | + per-pass exception would otherwise look identical to "nothing to | |
| 1068 | + reconcile" from the outside -- exactly the kind of quiet failure a | |
| 1069 | + 24/7-unattended loop can't afford.""" | |
| 1070 | + def loop(): | |
| 1071 | + while True: | |
| 1072 | + try: | |
| 1073 | + task_reconciliation.reconcile_once(db_path) | |
| 1074 | + except Exception: | |
| 1075 | + traceback.print_exc() | |
| 1076 | + time.sleep(interval_seconds) | |
| 1077 | + | |
| 1078 | + thread = threading.Thread(target=loop, daemon=True) | |
| 1079 | + thread.start() | |
| 1080 | + return thread | |
| 1081 | + | |
| 1082 | + | |
| 1045 | 1083 | def main(): |
| 1046 | 1084 | """U-037: CLI entry point (`python3 -m src.backend_server ...`) -- until |
| 1047 | 1085 | this Unit, `create_server()` was only ever instantiated in-process by |
| ... | ... | @@ -1059,10 +1097,15 @@ def main(): |
| 1059 | 1097 | parser.add_argument("--port", type=int, default=0) |
| 1060 | 1098 | parser.add_argument("--db-path", default=None) |
| 1061 | 1099 | parser.add_argument("--skill-repo-path", default=None) |
| 1100 | + parser.add_argument("--reconciliation-interval-seconds", type=int, default=_DEFAULT_RECONCILIATION_INTERVAL_SECONDS) | |
| 1101 | + parser.add_argument("--disable-reconciliation-loop", action="store_true") | |
| 1062 | 1102 | args = parser.parse_args() |
| 1063 | 1103 | |
| 1064 | 1104 | server = create_server(args.host, args.port, args.db_path, args.skill_repo_path) |
| 1065 | 1105 | |
| 1106 | + if not args.disable_reconciliation_loop: | |
| 1107 | + _start_reconciliation_loop(server.db_path, args.reconciliation_interval_seconds) | |
| 1108 | + | |
| 1066 | 1109 | def _handle_sigterm(signum, frame): |
| 1067 | 1110 | # server.shutdown() blocks until serve_forever()'s loop notices and |
| 1068 | 1111 | # returns -- calling it from the SAME thread that's running | ... | ... |
src/task_execution.py
| ... | ... | @@ -30,7 +30,7 @@ import threading |
| 30 | 30 | |
| 31 | 31 | from src import e2e_pipeline, org_node_lifecycle, schema, scheduler |
| 32 | 32 | |
| 33 | -_RESUMABLE_STATUSES = ("queued", "planning_brd_prd_sdd", "coding") | |
| 33 | +_RESUMABLE_STATUSES = ("queued", "planning_brd_prd_sdd", "coding", "validating") | |
| 34 | 34 | _DOC_ARTIFACT_TYPES = ("brd", "prd", "sdd", "benchmark") |
| 35 | 35 | _CODE_ARTIFACT_TYPES = ("code_diff", "test_report") |
| 36 | 36 | |
| ... | ... | @@ -95,9 +95,27 @@ def run_or_resume_task_lifecycle(conn, task_id, target_folder_path, goal_text): |
| 95 | 95 | ever happens BETWEEN phases (checked right before each org_node |
| 96 | 96 | trigger), so the only statuses a paused task can be resumed from are |
| 97 | 97 | 'queued' (nothing ran yet), 'planning_brd_prd_sdd' (Planner done, Coder |
| 98 | - not yet triggered), and 'coding' (Coder done, Validator not yet | |
| 99 | - triggered) -- anything else raises `TaskExecutionError` rather than | |
| 100 | - guessing at a mid-phase resume this module was never designed for.""" | |
| 98 | + not yet triggered), 'coding' (Coder done, Validator not yet triggered), | |
| 99 | + and 'validating' -- anything else raises `TaskExecutionError` rather | |
| 100 | + than guessing at a mid-phase resume this module was never designed for. | |
| 101 | + | |
| 102 | + **'validating' (2026-08-06, real stuck-task incident)**: this is NOT a | |
| 103 | + "between phases" resume like the other three -- `org_node_lifecycle. | |
| 104 | + trigger_org_node_full(..., "validator", ...)`'s blocking subprocess call | |
| 105 | + already completed successfully (that's the only way `task.status` could | |
| 106 | + have become 'validating' in the first place: the UPDATE to 'validating' | |
| 107 | + is the last thing that call does). Calling it a second time would fail | |
| 108 | + its own `_PRE_STATE["validator"] == "coding"` guard outright, since the | |
| 109 | + task is already past that state. The actual gap for a task stuck here is | |
| 110 | + narrower and safe to fill directly: `validate_implementation_with_own_ | |
| 111 | + graph()` -- which creates and runs the Validator's OWN Work Graph -- | |
| 112 | + never got invoked. Found for real: a task sat in 'validating' for 15+ | |
| 113 | + hours with zero `execution_event` rows and no `validator`-org_node | |
| 114 | + `work_graph_run` ever created, because nothing in production actually | |
| 115 | + polls `scheduler.run_scheduler_once()` (a separate, larger, tracked gap | |
| 116 | + -- see `docs/todo/scheduler-production-polling-loop-requirements.md`) | |
| 117 | + and whatever one-off call had driven this task that far had already | |
| 118 | + exited by the time Coder finished.""" | |
| 101 | 119 | status = conn.execute("SELECT status FROM task WHERE task_id = ?", (task_id,)).fetchone()[0] |
| 102 | 120 | if status not in _RESUMABLE_STATUSES: |
| 103 | 121 | raise TaskExecutionError("task {} is status={}, not resumable from here".format(task_id, status)) |
| ... | ... | @@ -126,11 +144,15 @@ def run_or_resume_task_lifecycle(conn, task_id, target_folder_path, goal_text): |
| 126 | 144 | benchmark_content=benchmark_content, test_dataset_content=test_dataset_content, |
| 127 | 145 | test_script_content=test_script_content, |
| 128 | 146 | ) |
| 129 | - else: # status == "coding" -- Coder already ran | |
| 147 | + else: # status in ("coding", "validating") -- Coder already ran | |
| 130 | 148 | code_artifact_ids = _latest_artifact_ids(conn, task_id, _CODE_ARTIFACT_TYPES) |
| 131 | 149 | |
| 132 | 150 | _check_not_paused(conn, task_id) |
| 133 | - org_node_lifecycle.trigger_org_node_full(conn, "validator", task_id, target_folder_path, e2e_pipeline._READY_PROMPT) | |
| 151 | + if status != "validating": | |
| 152 | + # "validating" means this exact call already ran once -- see the | |
| 153 | + # docstring's 'validating' section above. Calling it again would | |
| 154 | + # hit org_node_lifecycle's own PRE_STATE guard (needs "coding"). | |
| 155 | + org_node_lifecycle.trigger_org_node_full(conn, "validator", task_id, target_folder_path, e2e_pipeline._READY_PROMPT) | |
| 134 | 156 | verdict = e2e_pipeline.validate_implementation_with_own_graph( |
| 135 | 157 | conn, task_id, sdd_content, prd_content, goal_text, target_folder_path, |
| 136 | 158 | ) |
| ... | ... | @@ -146,6 +168,37 @@ def _mark_blocked(conn, task_id, exc): |
| 146 | 168 | scheduler._block_task(conn, task_id, reason, detail=str(exc)) |
| 147 | 169 | |
| 148 | 170 | |
| 171 | +# 2026-08-06 (task_reconciliation): in-process guard against dispatching the | |
| 172 | +# SAME task_id twice concurrently -- e.g. the console's Start button firing | |
| 173 | +# while a reconciliation pass (task_reconciliation.py) has already picked up | |
| 174 | +# the same stale task, or two rapid double-clicks on Start. Deliberately | |
| 175 | +# in-memory only (not a DB column/lock): this only needs to protect against | |
| 176 | +# two threads inside THIS process racing each other; it does not (and isn't | |
| 177 | +# meant to) survive a process restart -- a restart's whole point is that | |
| 178 | +# nothing in this process is running anymore, so an empty set on startup is | |
| 179 | +# the correct state, not a bug. | |
| 180 | +_in_flight_lock = threading.Lock() | |
| 181 | +_in_flight_task_ids = set() | |
| 182 | + | |
| 183 | + | |
| 184 | +def is_in_flight(task_id): | |
| 185 | + with _in_flight_lock: | |
| 186 | + return task_id in _in_flight_task_ids | |
| 187 | + | |
| 188 | + | |
| 189 | +def _try_claim(task_id): | |
| 190 | + with _in_flight_lock: | |
| 191 | + if task_id in _in_flight_task_ids: | |
| 192 | + return False | |
| 193 | + _in_flight_task_ids.add(task_id) | |
| 194 | + return True | |
| 195 | + | |
| 196 | + | |
| 197 | +def _release(task_id): | |
| 198 | + with _in_flight_lock: | |
| 199 | + _in_flight_task_ids.discard(task_id) | |
| 200 | + | |
| 201 | + | |
| 149 | 202 | def start_task_execution_in_background(db_path, task_id, target_folder_path, goal_text): |
| 150 | 203 | """Spawns a daemon thread that runs (or resumes) this task's real |
| 151 | 204 | execution to completion. Own sqlite connection per thread -- same |
| ... | ... | @@ -155,7 +208,14 @@ def start_task_execution_in_background(db_path, task_id, target_folder_path, goa |
| 155 | 208 | `scheduler.finish_task_lifecycle` closing step (`close_task_done` / |
| 156 | 209 | `org_level_loop.run_fix_loop`) a scheduled task gets, so a manually |
| 157 | 210 | started one reaches the same real terminal state. Returns the Thread |
| 158 | - (already started) so callers/tests can `.join()` it if needed.""" | |
| 211 | + (already started) so callers/tests can `.join()` it if needed. | |
| 212 | + | |
| 213 | + Raises `TaskExecutionError` immediately (no thread spawned) if this | |
| 214 | + task_id already has an execution in flight in this process -- see | |
| 215 | + `_in_flight_task_ids` above.""" | |
| 216 | + if not _try_claim(task_id): | |
| 217 | + raise TaskExecutionError("task {} already has an execution in flight".format(task_id)) | |
| 218 | + | |
| 159 | 219 | def run(): |
| 160 | 220 | # check_same_thread=False (2026-08-06, F): same reasoning as |
| 161 | 221 | # scheduler.run_goal_to_completion's own conn -- this thread's conn |
| ... | ... | @@ -173,6 +233,7 @@ def start_task_execution_in_background(db_path, task_id, target_folder_path, goa |
| 173 | 233 | _mark_blocked(conn, task_id, e) |
| 174 | 234 | finally: |
| 175 | 235 | conn.close() |
| 236 | + _release(task_id) | |
| 176 | 237 | |
| 177 | 238 | thread = threading.Thread(target=run, daemon=True) |
| 178 | 239 | thread.start() |
| ... | ... | @@ -186,12 +247,20 @@ def request_pause(conn, task_id, reason): |
| 186 | 247 | trail (execution_event / blocked_reason) preserves which button the |
| 187 | 248 | user actually clicked. Only valid while a background execution could |
| 188 | 249 | plausibly be in flight; raises TaskExecutionError otherwise (nothing |
| 189 | - running to pause, or already terminal).""" | |
| 250 | + running to pause, or already terminal). | |
| 251 | + | |
| 252 | + 'validating' included (2026-08-06, same incident as | |
| 253 | + `run_or_resume_task_lifecycle`'s 'validating' section): a resumed | |
| 254 | + validation run stays in `task.status='validating'` for its whole | |
| 255 | + duration (`validate_implementation_with_own_graph` never updates | |
| 256 | + `task.status` itself, same as `implement_code` doesn't during | |
| 257 | + 'coding') -- excluding it here would leave that in-flight run with no | |
| 258 | + way to request a pause/stop, unlike the other two resumable phases.""" | |
| 190 | 259 | row = conn.execute("SELECT project_id, status FROM task WHERE task_id = ?", (task_id,)).fetchone() |
| 191 | 260 | if row is None: |
| 192 | 261 | raise TaskExecutionError("no such task: " + task_id) |
| 193 | 262 | project_id, status = row |
| 194 | - if status not in ("planning_brd_prd_sdd", "coding"): | |
| 263 | + if status not in ("planning_brd_prd_sdd", "coding", "validating"): | |
| 195 | 264 | raise TaskExecutionError( |
| 196 | 265 | "task {} is status={}, nothing in-flight to pause/stop".format(task_id, status) |
| 197 | 266 | ) | ... | ... |
src/task_reconciliation.py
0 → 100644
| 1 | +"""Periodic recovery for tasks abandoned mid-flight (2026-08-06, real | |
| 2 | +incident: a task sat in status='validating' for 15+ hours with zero | |
| 3 | +`execution_event` activity and no live process working on it, because | |
| 4 | +whatever one-off call had driven it that far had already exited and | |
| 5 | +nothing in production polls for orphaned resumable tasks). | |
| 6 | + | |
| 7 | +Scope: FR-2 only from `docs/todo/scheduler-production-polling-loop- | |
| 8 | +requirements.md` (in-flight task reconciliation) -- deliberately NOT FR-1 | |
| 9 | +(new-goal auto-dispatch via `scheduler.run_scheduler_once()`), which is a | |
| 10 | +separate, larger, deliberately-not-bundled decision (see that doc's | |
| 11 | +non-goals/risks: "改变系统自主权边界"). This module only ever resumes a | |
| 12 | +task that already exists and was already in progress; it never creates a | |
| 13 | +new task or starts work nobody asked for. | |
| 14 | + | |
| 15 | +A task only becomes a reconciliation candidate if ALL of: | |
| 16 | +1. `task.status` is in `task_execution._RESUMABLE_STATUSES`, and | |
| 17 | +2. it has no execution happening in THIS process right now | |
| 18 | + (`task_execution.is_in_flight()` -- covers the common case where the | |
| 19 | + console's Start button and this loop share the same guard, so an | |
| 20 | + actively-running task is never double-dispatched), and | |
| 21 | +3. its most recent `execution_event` is older than `stale_after_seconds` | |
| 22 | + (or it has none at all, in which case `task.created_at` is used) -- | |
| 23 | + deliberately NOT `task.updated_at`, which does not change while a | |
| 24 | + phase is genuinely in progress (`implement_code`/ | |
| 25 | + `validate_implementation_with_own_graph` never touch it mid-phase -- | |
| 26 | + only the `task_status_changed` transitions do). Using | |
| 27 | + `task.updated_at` was the real blind spot during this incident's own | |
| 28 | + diagnosis: it looked "stale" for reasons unrelated to whether the task | |
| 29 | + was actually still being worked on. | |
| 30 | + | |
| 31 | +`_DEFAULT_STALE_AFTER_SECONDS` (1800s = 30 min) is comfortably above the | |
| 32 | +longest normal single-node blocking call in this codebase (Validator's | |
| 33 | +own work graph, `timeout=1200s`) so a node that's still genuinely inside | |
| 34 | +one blocking `claude -p` call is never misdiagnosed as abandoned -- see | |
| 35 | +the requirements doc's FR-3/non-goal #4 for why this doesn't need to be | |
| 36 | +more precise than that for v1. | |
| 37 | +""" | |
| 38 | + | |
| 39 | +import time | |
| 40 | +from datetime import datetime, timezone | |
| 41 | + | |
| 42 | +from src import schema, task_execution | |
| 43 | + | |
| 44 | +_DEFAULT_STALE_AFTER_SECONDS = 1800 | |
| 45 | + | |
| 46 | + | |
| 47 | +def _to_epoch(sqlite_timestamp): | |
| 48 | + # Same parsing as work_node_run._parse_sqlite_timestamp: sqlite's | |
| 49 | + # CURRENT_TIMESTAMP / *_at defaults are UTC 'YYYY-MM-DD HH:MM:SS' with | |
| 50 | + # no timezone marker. | |
| 51 | + return datetime.strptime(sqlite_timestamp, "%Y-%m-%d %H:%M:%S").replace(tzinfo=timezone.utc).timestamp() | |
| 52 | + | |
| 53 | + | |
| 54 | +def find_stale_resumable_tasks(conn, stale_after_seconds=_DEFAULT_STALE_AFTER_SECONDS, now=time.time): | |
| 55 | + """Returns [{"task_id", "target_folder_path", "goal_text"}, ...] for | |
| 56 | + every task that's a genuine reconciliation candidate. Read-only -- | |
| 57 | + does not dispatch anything, kept separate from `reconcile_once()` so | |
| 58 | + candidate selection is independently testable without spinning up | |
| 59 | + real background threads.""" | |
| 60 | + cutoff = now() - stale_after_seconds | |
| 61 | + placeholders = ",".join("?" * len(task_execution._RESUMABLE_STATUSES)) | |
| 62 | + rows = conn.execute( | |
| 63 | + "SELECT t.task_id, p.target_folder_path, t.goal_text, t.created_at, " | |
| 64 | + "(SELECT MAX(e.created_at) FROM execution_event e WHERE e.task_id = t.task_id) AS last_event_at " | |
| 65 | + "FROM task t JOIN project p ON p.project_id = t.project_id " | |
| 66 | + "WHERE t.status IN ({})".format(placeholders), | |
| 67 | + task_execution._RESUMABLE_STATUSES, | |
| 68 | + ).fetchall() | |
| 69 | + | |
| 70 | + candidates = [] | |
| 71 | + for task_id, target_folder_path, goal_text, created_at, last_event_at in rows: | |
| 72 | + if task_execution.is_in_flight(task_id): | |
| 73 | + continue | |
| 74 | + last_activity = _to_epoch(last_event_at or created_at) | |
| 75 | + if last_activity >= cutoff: | |
| 76 | + continue | |
| 77 | + candidates.append({"task_id": task_id, "target_folder_path": target_folder_path, "goal_text": goal_text}) | |
| 78 | + return candidates | |
| 79 | + | |
| 80 | + | |
| 81 | +def reconcile_once(db_path, stale_after_seconds=_DEFAULT_STALE_AFTER_SECONDS, now=time.time): | |
| 82 | + """One reconciliation pass: find candidates, dispatch each via | |
| 83 | + `task_execution.start_task_execution_in_background()`. Uses its own | |
| 84 | + short-lived connection for the scan, closed before dispatching -- the | |
| 85 | + background threads each open their own (same pattern as | |
| 86 | + `scheduler.py`). Returns the candidate list (dispatched or not) for | |
| 87 | + callers/tests to inspect. | |
| 88 | + | |
| 89 | + A candidate that fails to dispatch (e.g. `TaskExecutionError` because | |
| 90 | + something else claimed it between the scan and here -- a real race, | |
| 91 | + not a bug) is skipped, not treated as a fatal error for the whole | |
| 92 | + pass: 04-P's "调度器继续执行队列中其他任务" applies here the same way | |
| 93 | + it does in `scheduler.run_scheduler_once`.""" | |
| 94 | + conn = schema.connect(db_path) | |
| 95 | + try: | |
| 96 | + candidates = find_stale_resumable_tasks(conn, stale_after_seconds, now) | |
| 97 | + finally: | |
| 98 | + conn.close() | |
| 99 | + for c in candidates: | |
| 100 | + try: | |
| 101 | + task_execution.start_task_execution_in_background( | |
| 102 | + db_path, c["task_id"], c["target_folder_path"], c["goal_text"] | |
| 103 | + ) | |
| 104 | + except Exception: | |
| 105 | + pass | |
| 106 | + return candidates | ... | ... |
src/test_task_execution.py
| ... | ... | @@ -10,6 +10,7 @@ import json |
| 10 | 10 | import os |
| 11 | 11 | import subprocess |
| 12 | 12 | import tempfile |
| 13 | +import threading | |
| 13 | 14 | import unittest |
| 14 | 15 | from unittest.mock import patch |
| 15 | 16 | |
| ... | ... | @@ -136,6 +137,52 @@ class ResumeFromPlanningTest(TaskExecutionTestBase): |
| 136 | 137 | self.assertEqual(mock_trigger.call_args[0][0], "validator") |
| 137 | 138 | |
| 138 | 139 | |
| 140 | +class ResumeFromValidatingTest(TaskExecutionTestBase): | |
| 141 | + """2026-08-06 real incident: a task stuck in 'validating' for 15+ hours | |
| 142 | + with no validator work_graph_run ever created, because nothing in | |
| 143 | + production polls scheduler.run_scheduler_once() and whatever one-off | |
| 144 | + call drove it that far had already exited. Resuming from 'validating' | |
| 145 | + must skip BOTH Planner and Coder (already done) AND the | |
| 146 | + trigger_org_node_full("validator", ...) readiness call (already ran | |
| 147 | + once -- that's literally how status became 'validating'), going | |
| 148 | + straight to validate_implementation_with_own_graph().""" | |
| 149 | + | |
| 150 | + def test_skips_readiness_trigger_runs_validation_only(self): | |
| 151 | + self._insert_task("task-1", status="validating", assigned_org_node="validator") | |
| 152 | + self._write_artifact("task-1", "prd", "# PRD content") | |
| 153 | + self._write_artifact("task-1", "sdd", "# SDD content") | |
| 154 | + self._write_artifact("task-1", "benchmark", "# Benchmark content") | |
| 155 | + self._write_artifact("task-1", "code_diff", "diff content") | |
| 156 | + self._write_artifact("task-1", "test_report", "report content") | |
| 157 | + | |
| 158 | + with patch.object(org_node_lifecycle, "trigger_org_node", side_effect=_fake_ready_trigger) as mock_ready, \ | |
| 159 | + patch.object(work_graph_execute, "write_workflow_script"), \ | |
| 160 | + patch.object(work_graph_execute, "execute_work_graph") as mock_execute, \ | |
| 161 | + patch.object(org_node_trigger, "trigger_org_node", return_value="VERDICT: PASS") as mock_trigger: | |
| 162 | + mock_execute.side_effect = [ | |
| 163 | + {"content": "# Validator's own Benchmark"}, | |
| 164 | + {"content": "N/A: no dataset needed"}, | |
| 165 | + {"content": "import sys\nsys.exit(0)\n"}, | |
| 166 | + ] | |
| 167 | + result = task_execution.run_or_resume_task_lifecycle(self.conn, "task-1", self.tmp.name, "a goal") | |
| 168 | + | |
| 169 | + self.assertEqual(result["verdict"]["verdict"], "PASS") | |
| 170 | + self.assertEqual(result["code_artifact_ids"]["code_diff"], "art-code_diff") | |
| 171 | + # the readiness trigger (trigger_org_node_full's own PRE_STATE-guarded | |
| 172 | + # call) must NOT fire a second time -- it already succeeded once to | |
| 173 | + # get the task into 'validating' in the first place, and calling it | |
| 174 | + # again would hit org_node_lifecycle's own "needs status=coding" guard. | |
| 175 | + mock_ready.assert_not_called() | |
| 176 | + # only the real work_graph_run's own final call happened | |
| 177 | + mock_trigger.assert_called_once() | |
| 178 | + self.assertEqual(mock_trigger.call_args[0][0], "validator") | |
| 179 | + # a brand-new validator work_graph_run was created (none existed before) | |
| 180 | + rows = self.conn.execute( | |
| 181 | + "SELECT run_id FROM work_graph_run WHERE task_id = 'task-1' AND org_node = 'validator'" | |
| 182 | + ).fetchall() | |
| 183 | + self.assertEqual(len(rows), 1) | |
| 184 | + | |
| 185 | + | |
| 139 | 186 | class ResumeUnresumableStatusTest(TaskExecutionTestBase): |
| 140 | 187 | def test_done_task_raises(self): |
| 141 | 188 | self._insert_task("task-1", status="done") |
| ... | ... | @@ -207,6 +254,14 @@ class RequestPauseTest(TaskExecutionTestBase): |
| 207 | 254 | result = task_execution.request_pause(self.conn, "task-1", "user_stopped") |
| 208 | 255 | self.assertEqual(result["blocked_reason"], "user_stopped") |
| 209 | 256 | |
| 257 | + def test_pauses_a_validating_task(self): | |
| 258 | + # 2026-08-06: 'validating' stays task.status for the whole duration | |
| 259 | + # of a resumed validation run (validate_implementation_with_own_graph | |
| 260 | + # never updates task.status itself), so it must be pausable too. | |
| 261 | + self._insert_task("task-1", status="validating") | |
| 262 | + result = task_execution.request_pause(self.conn, "task-1", "user_paused") | |
| 263 | + self.assertEqual(result["status"], "blocked_pending_human") | |
| 264 | + | |
| 210 | 265 | def test_cannot_pause_a_queued_task(self): |
| 211 | 266 | self._insert_task("task-1", status="queued") |
| 212 | 267 | with self.assertRaises(task_execution.TaskExecutionError): |
| ... | ... | @@ -228,6 +283,17 @@ class StartTaskExecutionInBackgroundTest(unittest.TestCase): |
| 228 | 283 | per thread would be a completely separate, empty database).""" |
| 229 | 284 | |
| 230 | 285 | def setUp(self): |
| 286 | + # Defense-in-depth against the 2026-08-06 pollution incident (see | |
| 287 | + # test_second_call_while_in_flight_raises_no_second_thread's own | |
| 288 | + # comment): `_in_flight_task_ids` is a process-wide global, and | |
| 289 | + # "task-1" is reused across many unrelated tests/files -- if any | |
| 290 | + # test's mocking is incomplete enough that a spawned thread outlives | |
| 291 | + # its own join(timeout=...), the claim leaks and silently fails | |
| 292 | + # OTHER tests depending on run order. Unconditionally clearing here | |
| 293 | + # makes that failure mode impossible regardless of what any | |
| 294 | + # individual test does right or wrong. | |
| 295 | + task_execution._release("task-1") | |
| 296 | + self.addCleanup(lambda: task_execution._release("task-1")) | |
| 231 | 297 | self.repo = tempfile.TemporaryDirectory() |
| 232 | 298 | self.addCleanup(self.repo.cleanup) |
| 233 | 299 | subprocess.run(["git", "init"], cwd=self.repo.name, check=True, capture_output=True) |
| ... | ... | @@ -300,6 +366,65 @@ class StartTaskExecutionInBackgroundTest(unittest.TestCase): |
| 300 | 366 | status = conn.execute("SELECT status FROM task WHERE task_id = 'task-1'").fetchone()[0] |
| 301 | 367 | conn.close() |
| 302 | 368 | self.assertEqual(status, "done") |
| 369 | + # 2026-08-06 (task_reconciliation): the in-flight guard must release | |
| 370 | + # once the thread is done, so a LATER dispatch of the same task_id | |
| 371 | + # (e.g. a future reconciliation pass) isn't permanently blocked by a | |
| 372 | + # completed run. | |
| 373 | + self.assertFalse(task_execution.is_in_flight("task-1")) | |
| 374 | + | |
| 375 | + def test_second_call_while_in_flight_raises_no_second_thread(self): | |
| 376 | + # 2026-08-06 (task_reconciliation): guards against the console's | |
| 377 | + # Start button and a reconciliation pass racing to dispatch the SAME | |
| 378 | + # task_id concurrently -- the second call must fail fast, not spawn | |
| 379 | + # a second thread that would run the same task twice. | |
| 380 | + # | |
| 381 | + # Fully mocks the same real work the OTHER StartTaskExecutionIn | |
| 382 | + # BackgroundTest tests mock (write_workflow_script/execute_work_graph/ | |
| 383 | + # org_node_trigger.trigger_org_node), not just the readiness trigger | |
| 384 | + # this test blocks on -- an earlier version of this test only | |
| 385 | + # patched the readiness trigger, so once unblocked the thread went on | |
| 386 | + # to attempt REAL subprocess/file work, outlived this test's own | |
| 387 | + # join(timeout=10), and left "task-1" permanently claimed in the | |
| 388 | + # process-wide `_in_flight_task_ids` set -- silently failing every | |
| 389 | + # OTHER test in the suite that reuses the literal task_id "task-1" | |
| 390 | + # (nearly all of them), depending on run order. Caught by running | |
| 391 | + # the full discover -s src suite, not by running this file alone. | |
| 392 | + self._write_artifact("task-1", "prd", "# PRD") | |
| 393 | + self._write_artifact("task-1", "sdd", "# SDD") | |
| 394 | + self._write_artifact("task-1", "benchmark", "# Benchmark") | |
| 395 | + self._write_artifact("task-1", "code_diff", "diff") | |
| 396 | + self._write_artifact("task-1", "test_report", "report") | |
| 397 | + | |
| 398 | + release_first_call = threading.Event() | |
| 399 | + entered_first_call = threading.Event() | |
| 400 | + | |
| 401 | + def blocking_trigger(org_node, prompt, target_folder_path, timeout=300): | |
| 402 | + entered_first_call.set() | |
| 403 | + release_first_call.wait(timeout=10) | |
| 404 | + return _fake_ready_trigger(org_node, prompt, target_folder_path, timeout) | |
| 405 | + | |
| 406 | + with patch.object(org_node_lifecycle, "trigger_org_node", side_effect=blocking_trigger), \ | |
| 407 | + patch.object(work_graph_execute, "write_workflow_script"), \ | |
| 408 | + patch.object(work_graph_execute, "execute_work_graph") as mock_execute, \ | |
| 409 | + patch.object(org_node_trigger, "trigger_org_node", return_value="VERDICT: PASS"): | |
| 410 | + mock_execute.side_effect = [ | |
| 411 | + {"content": "# Validator's own Benchmark"}, | |
| 412 | + {"content": "N/A: no dataset needed"}, | |
| 413 | + {"content": "import sys\nsys.exit(0)\n"}, | |
| 414 | + ] | |
| 415 | + thread = task_execution.start_task_execution_in_background( | |
| 416 | + self.db_path, "task-1", self.repo.name, "a goal", | |
| 417 | + ) | |
| 418 | + entered_first_call.wait(timeout=10) | |
| 419 | + self.assertTrue(task_execution.is_in_flight("task-1")) | |
| 420 | + with self.assertRaises(task_execution.TaskExecutionError): | |
| 421 | + task_execution.start_task_execution_in_background( | |
| 422 | + self.db_path, "task-1", self.repo.name, "a goal", | |
| 423 | + ) | |
| 424 | + release_first_call.set() | |
| 425 | + thread.join(timeout=10) | |
| 426 | + | |
| 427 | + self.assertFalse(task_execution.is_in_flight("task-1")) | |
| 303 | 428 | |
| 304 | 429 | def test_generic_failure_marks_blocked(self): |
| 305 | 430 | self._write_artifact("task-1", "prd", "# PRD") | ... | ... |
src/test_task_reconciliation.py
0 → 100644
| 1 | +"""task_reconciliation.py tests (2026-08-06, real 15h-stuck-task incident): | |
| 2 | +mocked at the subprocess boundary for reconcile_once, real sqlite for | |
| 3 | +candidate-selection logic -- same split as test_task_execution.py. | |
| 4 | + | |
| 5 | +Run: python3 -m unittest src.test_task_reconciliation -v | |
| 6 | +""" | |
| 7 | + | |
| 8 | +import subprocess | |
| 9 | +import tempfile | |
| 10 | +import unittest | |
| 11 | +from datetime import datetime, timezone | |
| 12 | +from unittest.mock import patch | |
| 13 | + | |
| 14 | +from src import project_scaffold, schema, task_execution, task_reconciliation | |
| 15 | + | |
| 16 | +_NOW_EPOCH = 2_000_000_000 # fixed reference point, independent of wall clock | |
| 17 | + | |
| 18 | + | |
| 19 | +def _ts(epoch_seconds): | |
| 20 | + return datetime.fromtimestamp(epoch_seconds, tz=timezone.utc).strftime("%Y-%m-%d %H:%M:%S") | |
| 21 | + | |
| 22 | + | |
| 23 | +class ReconciliationTestBase(unittest.TestCase): | |
| 24 | + def setUp(self): | |
| 25 | + self.tmp = tempfile.TemporaryDirectory() | |
| 26 | + self.addCleanup(self.tmp.cleanup) | |
| 27 | + subprocess.run(["git", "init"], cwd=self.tmp.name, check=True, capture_output=True) | |
| 28 | + self.conn = schema.connect(":memory:") | |
| 29 | + schema.create_schema(self.conn) | |
| 30 | + project = project_scaffold.create_project(self.conn, self.tmp.name, init_git_if_missing=False) | |
| 31 | + self.project_id = project["project_id"] | |
| 32 | + | |
| 33 | + def tearDown(self): | |
| 34 | + self.conn.close() | |
| 35 | + | |
| 36 | + def _insert_task(self, task_id, status, created_at_epoch, assigned_org_node="planner"): | |
| 37 | + self.conn.execute( | |
| 38 | + "INSERT INTO task (task_id, project_id, goal_text, task_type, status, assigned_org_node, created_at) " | |
| 39 | + "VALUES (?, ?, 'a goal', 'goal', ?, ?, ?)", | |
| 40 | + (task_id, self.project_id, status, assigned_org_node, _ts(created_at_epoch)), | |
| 41 | + ) | |
| 42 | + self.conn.commit() | |
| 43 | + | |
| 44 | + def _insert_event(self, task_id, created_at_epoch, event_type="log_appended"): | |
| 45 | + self.conn.execute( | |
| 46 | + "INSERT INTO execution_event (event_id, project_id, task_id, event_type, payload, created_at) " | |
| 47 | + "VALUES (?, ?, ?, ?, '{}', ?)", | |
| 48 | + ("ev-" + task_id + "-" + str(created_at_epoch), self.project_id, task_id, event_type, _ts(created_at_epoch)), | |
| 49 | + ) | |
| 50 | + self.conn.commit() | |
| 51 | + | |
| 52 | + | |
| 53 | +class FindStaleResumableTasksTest(ReconciliationTestBase): | |
| 54 | + def test_finds_task_with_no_activity_at_all(self): | |
| 55 | + self._insert_task("task-1", "coding", created_at_epoch=_NOW_EPOCH - 3600) | |
| 56 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 57 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 58 | + ) | |
| 59 | + self.assertEqual([c["task_id"] for c in result], ["task-1"]) | |
| 60 | + | |
| 61 | + def test_excludes_task_with_recent_event(self): | |
| 62 | + self._insert_task("task-1", "validating", created_at_epoch=_NOW_EPOCH - 7200) | |
| 63 | + self._insert_event("task-1", created_at_epoch=_NOW_EPOCH - 60) # 1 min ago -- fresh | |
| 64 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 65 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 66 | + ) | |
| 67 | + self.assertEqual(result, []) | |
| 68 | + | |
| 69 | + def test_uses_most_recent_event_not_earliest(self): | |
| 70 | + self._insert_task("task-1", "coding", created_at_epoch=_NOW_EPOCH - 7200) | |
| 71 | + self._insert_event("task-1", created_at_epoch=_NOW_EPOCH - 5000) # old | |
| 72 | + self._insert_event("task-1", created_at_epoch=_NOW_EPOCH - 60) # recent -- MAX() must win | |
| 73 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 74 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 75 | + ) | |
| 76 | + self.assertEqual(result, []) | |
| 77 | + | |
| 78 | + def test_stale_event_still_flagged(self): | |
| 79 | + self._insert_task("task-1", "coding", created_at_epoch=_NOW_EPOCH - 7200) | |
| 80 | + self._insert_event("task-1", created_at_epoch=_NOW_EPOCH - 5000) # > 1800s ago | |
| 81 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 82 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 83 | + ) | |
| 84 | + self.assertEqual([c["task_id"] for c in result], ["task-1"]) | |
| 85 | + | |
| 86 | + def test_excludes_non_resumable_status(self): | |
| 87 | + self._insert_task("task-1", "done", created_at_epoch=_NOW_EPOCH - 100000) | |
| 88 | + self._insert_task("task-2", "blocked_pending_human", created_at_epoch=_NOW_EPOCH - 100000) | |
| 89 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 90 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 91 | + ) | |
| 92 | + self.assertEqual(result, []) | |
| 93 | + | |
| 94 | + def test_excludes_in_flight_task(self): | |
| 95 | + self._insert_task("task-1", "validating", created_at_epoch=_NOW_EPOCH - 100000) | |
| 96 | + with patch.object(task_execution, "is_in_flight", return_value=True): | |
| 97 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 98 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 99 | + ) | |
| 100 | + self.assertEqual(result, []) | |
| 101 | + | |
| 102 | + def test_candidate_carries_target_folder_path_and_goal(self): | |
| 103 | + self._insert_task("task-1", "queued", created_at_epoch=_NOW_EPOCH - 100000) | |
| 104 | + result = task_reconciliation.find_stale_resumable_tasks( | |
| 105 | + self.conn, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 106 | + ) | |
| 107 | + self.assertEqual(result, [{"task_id": "task-1", "target_folder_path": self.tmp.name, "goal_text": "a goal"}]) | |
| 108 | + | |
| 109 | + | |
| 110 | +class ReconcileOnceTest(unittest.TestCase): | |
| 111 | + """Real file db (own connection per dispatched thread, same reasoning | |
| 112 | + as StartTaskExecutionInBackgroundTest) -- dispatch itself is mocked so | |
| 113 | + this stays at the "did we correctly decide to call it" boundary, not | |
| 114 | + a re-test of run_or_resume_task_lifecycle's own mechanics.""" | |
| 115 | + | |
| 116 | + def setUp(self): | |
| 117 | + self.tmp = tempfile.TemporaryDirectory() | |
| 118 | + self.addCleanup(self.tmp.cleanup) | |
| 119 | + subprocess.run(["git", "init"], cwd=self.tmp.name, check=True, capture_output=True) | |
| 120 | + self.tmp_db = tempfile.NamedTemporaryFile(suffix=".db", delete=False) | |
| 121 | + self.tmp_db.close() | |
| 122 | + self.db_path = self.tmp_db.name | |
| 123 | + self.addCleanup(lambda: __import__("os").path.exists(self.db_path) and __import__("os").remove(self.db_path)) | |
| 124 | + | |
| 125 | + conn = schema.connect(self.db_path) | |
| 126 | + schema.create_schema(conn) | |
| 127 | + project = project_scaffold.create_project(conn, self.tmp.name, init_git_if_missing=False) | |
| 128 | + self.project_id = project["project_id"] | |
| 129 | + conn.execute( | |
| 130 | + "INSERT INTO task (task_id, project_id, goal_text, task_type, status, assigned_org_node, created_at) " | |
| 131 | + "VALUES ('stale-1', ?, 'goal 1', 'goal', 'coding', 'coder', ?)", | |
| 132 | + (self.project_id, _ts(_NOW_EPOCH - 100000)), | |
| 133 | + ) | |
| 134 | + conn.execute( | |
| 135 | + "INSERT INTO task (task_id, project_id, goal_text, task_type, status, assigned_org_node, created_at) " | |
| 136 | + "VALUES ('fresh-1', ?, 'goal 2', 'goal', 'coding', 'coder', ?)", | |
| 137 | + (self.project_id, _ts(_NOW_EPOCH - 10)), | |
| 138 | + ) | |
| 139 | + conn.commit() | |
| 140 | + conn.close() | |
| 141 | + | |
| 142 | + def test_dispatches_only_stale_candidates(self): | |
| 143 | + with patch.object(task_execution, "start_task_execution_in_background") as mock_start: | |
| 144 | + result = task_reconciliation.reconcile_once( | |
| 145 | + self.db_path, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 146 | + ) | |
| 147 | + self.assertEqual([c["task_id"] for c in result], ["stale-1"]) | |
| 148 | + mock_start.assert_called_once_with(self.db_path, "stale-1", self.tmp.name, "goal 1") | |
| 149 | + | |
| 150 | + def test_one_dispatch_failure_does_not_block_others(self): | |
| 151 | + conn = schema.connect(self.db_path) | |
| 152 | + conn.execute( | |
| 153 | + "INSERT INTO task (task_id, project_id, goal_text, task_type, status, assigned_org_node, created_at) " | |
| 154 | + "VALUES ('stale-2', ?, 'goal 3', 'goal', 'validating', 'validator', ?)", | |
| 155 | + (self.project_id, _ts(_NOW_EPOCH - 100000)), | |
| 156 | + ) | |
| 157 | + conn.commit() | |
| 158 | + conn.close() | |
| 159 | + | |
| 160 | + with patch.object( | |
| 161 | + task_execution, "start_task_execution_in_background", | |
| 162 | + side_effect=[task_execution.TaskExecutionError("already in flight"), None], | |
| 163 | + ) as mock_start: | |
| 164 | + result = task_reconciliation.reconcile_once( | |
| 165 | + self.db_path, stale_after_seconds=1800, now=lambda: _NOW_EPOCH | |
| 166 | + ) | |
| 167 | + self.assertEqual(len(result), 2) | |
| 168 | + self.assertEqual(mock_start.call_count, 2) | |
| 169 | + | |
| 170 | + | |
| 171 | +if __name__ == "__main__": | |
| 172 | + unittest.main() | ... | ... |