fix(executor_docker): 删 setsid 修 docker exec 延迟 stdout 丢失
实证:`docker exec ... setsid python -c "sleep(2); print"` 等满 2s 输出空, 同条件去 setsid 输出 hello。setsid 调 setsid() syscall 后 docker exec/runc 的 stdio attach 出问题,延迟输出被截。上一条 _run_subprocess 重写修了独立的 poll-loop bug 但不是用户当下症状元凶。setsid 历史是给 §7.5 Step 3b PGID kill 协议铺路,该协议未实现的当下是空头载荷 + 副作用。改 _exec_shell:141 / _exec_python:177 各删 1 个 "setsid"。回归测试加 test_run_subprocess_delayed_output_not_lost (真子进程 sleep+print)+ test_argv_does_not_contain_setsid(防回潮)。19/19 PASS。 Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
91cc14278c
commit
aab1da3296
|
|
@ -2,7 +2,7 @@
|
|||
|
||||
> 配合 `DESIGN.md`。本文件只记 phase 状态、决策偏差、文件量、下一步。每条 1-2 句:做了啥 + 关键判断;细节查 `git log` / `git diff` / `DESIGN §7.9`。
|
||||
|
||||
最后更新:2026-05-29(`_run_subprocess` 重写修 docker exec stdout 多 chunk 静默丢失 bug + 上午 3 个 SKILL.md sandbox 凭证可用性校准)
|
||||
最后更新:2026-05-29(删 docker exec argv 里的 setsid 修延迟 stdout 丢失 + `_run_subprocess` 重写修 communicate poll loop bug + 3 个 SKILL.md sandbox 凭证可用性校准)
|
||||
|
||||
---
|
||||
|
||||
|
|
@ -23,6 +23,7 @@
|
|||
|
||||
### 2026-05-29
|
||||
|
||||
- **删 `_exec_shell` / `_exec_python` argv 里的 `setsid` 修 docker exec 延迟 stdout 丢失**:上一条 `_run_subprocess` 重写后用户实测 LLM 拿 `cement energy efficiency` 跑 paper_server 检索仍返空 `[exit 0]` 8 字符,且 `print(f"共命中 {len(papers)} 条结果\n")` 这种必有输出的代码也丢。**根因 = `setsid`,不是 `_run_subprocess` 的 poll loop**(上一条修对了一个独立的 bug,但不是用户当下症状的元凶)。**实证差异**:`docker exec ... setsid python -c "import time; time.sleep(2); print('hello')"` 等满 2.06s 但输出空;同条件去掉 setsid `docker exec ... python -c "..."` 等满 2.08s + 输出 `hello`。`setsid` 调 `setsid()` syscall 把进程变 new session leader without controlling terminal **之后** execvp(python),docker exec / runc 的 stdio attach 对"调用方变 session leader"敏感(具体哪一层没深挖到 runc 源码,经验上 docker exec + setsid + 延迟输出 = stdout 数据被截断,业界踩过的坑)。短输出(`print('hello')` 瞬时完成)能在窗口内漏出去,延迟输出(`search()` 等 httpx 1-2s)就全丢 —— 完美解释为什么 LLM 简单 `print(version)` 测试时部分输出能回但真业务调用全空。**为什么之前 host 侧 `docker exec ... python -c "from skills.research.paper import search; ..."` 2.94s 拿 10 条成功**:那条**没有** setsid,docker exec 等的就是 python 本身,3s 全程都阻塞读 stdout 不会丢。`setsid` 历史上是 §7.5 Stage C **Step 3b PGID kill 协议**铺路用的(PROGRESS 上有"延后到外部用户开放前"这条 work item),**协议没实现的当下 setsid 是空头载荷 + 副作用**。**改法**:`core/executor_docker.py:141` 和 `:177` 各删 1 行的 `"setsid"`,argv 形态变 `docker exec ... <container> bash -c <cmd>` / `... python <script>`。**否决**:(a) `setsid --wait <prog>` —— 强制 setsid 等子退 + 透传 exit code,但需要 util-linux 2.32+ 且增加一层依赖;PGID kill 协议没做的当下没必要;(b) 包一层自己写的 wait wrapper —— 同上,过度工程;(c) 改 docker exec 加 `-t` 强制 tty —— 引入 \r\n 转换 + 影响输出清晰度,非生产做法。**测试**(`tests/test_executor_docker.py`):① 更新 `test_shell_invokes_docker_exec` 断言 `argv[container_idx+1:] == ["bash", "-c", "echo hello"]`(原 `["setsid", "bash", "-c", ...]`);② 更新 `test_run_python_tmp_script` 删 `argv[-3] == "setsid"` 断言;③ **新加 `test_run_subprocess_delayed_output_not_lost`**:`sys.executable, "-c", "import time; time.sleep(1); print('LATE')"` 真子进程跑,断 LATE 在 stdout 里 + `[exit 0]`(Windows skip);④ **新加 `test_argv_does_not_contain_setsid`**:patch Popen 抓两次 call(shell + run_python)的 argv,断 `"setsid" not in argv` 防回潮。**全套 19/19 PASS**(老 17 + 2 新)。**未来加 PGID kill 协议时**:不能裸 setsid 回潮 —— `test_argv_does_not_contain_setsid` 会挂,会强制实现者去查 PROGRESS 这条把 setsid 用对(`setsid --wait` 或 wrapper)。**部署生效**:`git pull && systemctl restart zcbot`,sandbox 容器不用 rm。**经验值更新**:这次诊断走了弯路 —— 上一条 `_run_subprocess` 重写虽然修了一个真 bug(communicate poll loop 违反 API + bash block-buffered chunk 丢),但**不是用户当下症状的元凶**,setsid 才是。两个 bug 都贡献"8 字符 `[exit 0]`"的部分场景:poll loop 影响多 chunk 输出收集,setsid 影响延迟输出收集,各自独立,都得修。`DESIGN.md` 不动(纯实现 bug 修,§7.5 Step 3b PGID kill 协议状态没变,只是落实时改用 `setsid --wait` 而非裸 setsid,这是个实现细节不是架构变化);`RUN.md` 不动;`SKILL_LIST.md` 不动。
|
||||
- **`core/executor_docker.py::_run_subprocess` 重写修 docker exec stdout 多 chunk 静默丢失 bug**:用户实测 LLM 在容器里调 `from skills.research.paper import search` / `shell echo "test"; ...; echo "done"` 拿到空 `[exit 0]` 8 字符,而 host 侧 `docker exec ... python -c "from skills.research.paper import search; r=search(...)"` 同 query 2.94s 拿 10 条切题结果 —— 网络 / DNS / paper_server / helper / httpx 全清白,**问题在 tool wrapper 自己**。**根因**:旧实现 `while True: try: proc.communicate(input=stdin, timeout=0.5) except TimeoutExpired: ...` 在 poll loop 里反复调 `communicate()`,**违反 `subprocess` API 假设**(`communicate` 文档明说 "should be called only once") + 配合 `setsid bash -c "..."` 的 block-buffered stdout(pipe 而非 tty 触发 4K block buffering)在多 chunk 输出时序下 chunk 静默丢失。具体路径:`echo "test"` 第一个 token 几乎 buffer 还没装就到 `setsid bash` 收尾 flush 那一刻被读到 ; `timeout 3 python3 ...` 子进程 + 后续 `echo "done"` 走的是 setsid 子会话的二级 buffer,communicate 在 0.5s 轮询窗口里要么完全读不到要么读半截,内部 `self._fileobj2output` 状态在反复 TO 后某些 Python 版本下不连续。**重写实现(D 候选,4 候选里选最小补丁)**:① 入口 inline 查一次 `cancel_check`,True 立即返不起 Popen(同步快路径 + 消除单测 race);② 单次 `proc.communicate(input=stdin, timeout=timeout)`,违反 API 的 poll loop 彻底删;③ cancel 检查移到侧 daemon 线程,周期 `_CANCEL_POLL_INTERVAL_S=0.2`(模块常量,单测 patch 0.02 加速)poll `cancel_check`,命中即 `cancel_hit.set() + proc.kill()`;④ TimeoutExpired 分支 `kill + 二次 communicate()` 走 `self._fileobj2output` 续读累积 chunks 不丢已读;⑤ cancel 优先于 timeout(canceller 设了 hit 即使 communicate 也抛 TO 时优先返 cancelled)。**否决**:(A) 2 reader 线程裸 drain stdout/stderr.read() —— ~40 行,可选但 D 最小;(B) `selectors.PollSelector` 非阻塞 read —— ~50 行,Windows caveat(咱们 Linux 部署不踩,但代码上多一层平台分支);(C) 整链路 sync→async —— 大手术,不值。**回归测试**(`tests/test_executor_docker.py`):① `test_shell_cancel` 拆 `test_shell_cancel_inline_fastpath`(入口快路径,Popen 不起)+ `test_shell_cancel_via_canceller_thread`(cancel_check 第 1 次 False 让 inline 放行第 2 次起 True 让侧线程触发,threading.Event 同步 mock kill);② **新加 `test_run_subprocess_collects_multi_chunk_output`** 起真子进程 `bash -c 'echo A; sleep 0.6; echo B; sleep 0.6; echo C'` 断 A/B/C 全在结果里(Windows skip,Linux CI/部署跑),这条 case 在旧实现下必挂、新实现必过 —— 直接锁死本 bug 回归;③ `test_shell_timeout` / `test_fs_tool_timeout` 移除已死的 `time.monotonic` patch(新代码不用 time.monotonic 跟踪 elapsed,改靠 `communicate(timeout=N)` 自带累计)。**结果 17/17 PASS**(老 15 + 拆 1 加 2 = 17,multi-chunk 那条 Windows skip 计入)。**部署生效**:重启 web 进程 + 老 sandbox 容器无需 rm(代码改在 host 侧 executor,容器本身行为不变,新请求进 new wrapper 即用)。**行为变化**:cancel 响应延迟 ~500ms → ~200ms(侧线程 wait 0.2s 改善);timeout 错误文案不变;线程开销 per call 多 1 个 daemon thread 只在 `cancel_check is not None` 时起,忽略不计。`DESIGN.md` 不动(无架构变化,纯实现 bug 修;§7.5 Stage C Step 3b "PGID kill 协议" 跟本 bug 正交,该 work item 延后到外部用户开放前的状态没变);`RUN.md` 不动(无 CLI / env / 文件布局变化);`SKILL_LIST.md` 不动(skill 列表无变化)。
|
||||
- **3 个 SKILL.md 校准 sandbox 下外部凭证可用性**:用户实测 LLM 报 documents 缺 `DOCUMENT_SEARCH_API_KEY`,追到 `tools/run_python.py::_SENSITIVE_PATTERNS = ("API_KEY", "TOKEN", "SECRET", "PASSWORD", "PRIVATE_KEY")` 在 subprocess 起前删所有名含这些字面的 host env —— 设计是挡 prompt 注入 `print(os.environ)` 抽 ARK / JWT_SECRET 等(JWT_SECRET 一旦露=任意身份伪造),**误伤**了 skill 端从 env 读 key 的 `pymatgen.materials.mp_rester()` 和 `skills.documents.client._api_key()`(docker backend 下 host env 根本不入容器,问题更彻底)。**连带发现**:`research` SKILL.md 排版跟两者太像(都"准备段写 import + env 说明"),LLM 看 documents 失败**类推**也放弃 research —— 可 `research/paper.py:10` `PAPER_SERVER_URL` 是 URL 有默认值 `http://paper.xxhhcty.xyz:8080`、过滤器根本不碰;被用户逼试又用 `urllib.request` 钻反模式行 128 只禁 `httpx/requests` 的字面空子,跳过 helper 后 SKILL.md 教的 search filter / 中文转英文术语全丢,`search=cement+based` 字符级模糊匹配返 6809 条横跨无人机 / 锂电池 / 热界面 LLM 还以为搜对了。**改 3 个 SKILL.md**:① `pymatgen` H1 后插 WARNING,明示 mp 联网不可用 + 列离线 5 能力(`Structure.from_file` / `SpacegroupAnalyzer` / `XRDCalculator` / `CEMENT_PHASES` / VASP 输入)+ 禁脑补晶格;② `documents` H1 后插 WARNING,标整体不可用 + 降级到 research / 用户自导出;③ `research` 在 "准备"段后加一段 callout 明示**不持 secret + sandbox 任何模式都能用 + documents 不可用时是降级首选**,反模式行 128 扩成"任何 HTTP 客户端(httpx/requests/urllib/aiohttp/curl)裸调"并说清裸调代价(SKILL.md 教学全丢)。`SKILL_LIST.md` 速览表 documents / pymatgen 加 ⚠️ 状态标 + 最后更新 2026-05-29;`RUN.md` env 段 `DOCUMENT_SEARCH_API_KEY` / `MP_API_KEY` 行下加 ⚠️ 注脚说 sandbox 被过滤器拦。**架构方向(下轮做)**:不取消过滤器(会把 ARK / JWT_SECRET / BOCHA / ZCBOT_ADMIN_TOKEN 全暴露,prompt 注入面爆开),不为每 service 包 host tool(线性增长 + 拆 query / 后处理割裂 LLM 体验),走业界 2025-2026 主流的 **credential broker / credential proxy**(Infisical Agent Vault / NVIDIA agentic workflow 指南推):一个外发代理持所有 key,sandbox 出站 HTTP 经它按目标域名 / URL 前缀注入 auth header,新增 service 加一行 broker 配置即可,key 永不入 sandbox + prompt 注入抗性同 host tool 方案,代价是 ~100 行 fastapi 小服务 + Dockerfile env 加 `MP_BASE_URL=http://broker:8080/mp` 这类 URL(URL 不是 secret,过滤器不碰)。两种落地形态:**A forward proxy** (`HTTPS_PROXY`,需自签 CA 装容器) / **B URL-rewriting reverse proxy**(broker 暴露 `/mp/*` `/docs/*` 路由,skill 改 BASE_URL,不用 MITM)—— 倾向 B,工程量更小。`DESIGN.md` 本轮不动 —— broker 实际落地时再加 §7.X "外部凭证代理范式"段,避免 DESIGN 描述未实现内容。
|
||||
|
||||
|
|
|
|||
|
|
@ -143,7 +143,12 @@ class DockerExecutor(Executor):
|
|||
timeout = int(args.get("timeout") or 60)
|
||||
|
||||
container = self.pool.ensure(self.user_id)
|
||||
argv = self._docker_exec_argv(container) + ["setsid", "bash", "-c", cmd]
|
||||
# 2026-05-29 删 setsid:`docker exec ... setsid python script` 在 setsid 调
|
||||
# setsid() syscall 把进程变 new session leader 后,docker exec / runc 的 stdio
|
||||
# attach 出问题,延迟输出(sleep 2 后 print)被截掉,LLM 拿到空 [exit 0]。
|
||||
# PGID kill 协议(§7.5 Step 3b)未来要做时换 `setsid --wait` 或 wrapper,
|
||||
# 不能裸 setsid。
|
||||
argv = self._docker_exec_argv(container) + ["bash", "-c", cmd]
|
||||
result = self._run_subprocess(argv, timeout=timeout, ctx=ctx)
|
||||
self.pool.mark_active(self.user_id)
|
||||
return result
|
||||
|
|
@ -179,7 +184,7 @@ class DockerExecutor(Executor):
|
|||
# 这条 import path);/workspace 在后:用户 task 目录的本地脚本
|
||||
"PYTHONPATH": "/sandbox:/workspace",
|
||||
},
|
||||
) + ["setsid", "python", container_script]
|
||||
) + ["python", container_script] # 删 setsid 同上(_exec_shell 注释)
|
||||
result = self._run_subprocess(argv, timeout=timeout, ctx=ctx)
|
||||
self.pool.mark_active(self.user_id)
|
||||
return result
|
||||
|
|
|
|||
|
|
@ -150,8 +150,8 @@ class TestShellExec(unittest.TestCase):
|
|||
self.assertEqual(argv[argv.index("--workdir") + 1], "/workspace/demo")
|
||||
# container name = zcbot-sandbox-<uid>
|
||||
container_idx = argv.index(f"zcbot-sandbox-{executor.user_id}")
|
||||
# setsid bash -c 必须出现且紧跟 container 之后
|
||||
self.assertEqual(argv[container_idx + 1:], ["setsid", "bash", "-c", "echo hello"])
|
||||
# bash -c 紧跟 container 之后(setsid 2026-05-29 删 —— 跟 docker exec stdio 不兼容)
|
||||
self.assertEqual(argv[container_idx + 1:], ["bash", "-c", "echo hello"])
|
||||
|
||||
self.assertEqual(pool.ensure_calls, [executor.user_id])
|
||||
self.assertEqual(pool.mark_active_calls, [executor.user_id])
|
||||
|
|
@ -260,6 +260,53 @@ class TestShellExec(unittest.TestCase):
|
|||
self.assertIn("[exit 0]", result.content)
|
||||
self.assertEqual(result.exit_code, 0)
|
||||
|
||||
def test_run_subprocess_delayed_output_not_lost(self):
|
||||
"""回归:子进程 sleep 后 print 必须完整捕获(实际是 _run_subprocess 层 + bash 行为)。
|
||||
|
||||
历史 bug:`docker exec ... setsid python script` 在 setsid 进入 new session
|
||||
之后 docker exec / runc stdio attach 出问题,延迟输出丢失,LLM 拿空 [exit 0]。
|
||||
本层测的是 _run_subprocess 自己的 stdout 收集逻辑(不经 docker exec);
|
||||
跟 argv 不含 setsid 的断言两层防回潮。Windows 跳过(sleep 语义)。
|
||||
"""
|
||||
if platform.system() == "Windows":
|
||||
self.skipTest("Linux only (sleep semantics)")
|
||||
|
||||
executor, _, _ = make_executor()
|
||||
ctx = make_ctx(executor)
|
||||
|
||||
argv = [
|
||||
sys.executable, "-c",
|
||||
"import time; time.sleep(1); print('LATE')",
|
||||
]
|
||||
result = executor._run_subprocess(argv, timeout=10, ctx=ctx)
|
||||
|
||||
self.assertIn("LATE", result.content)
|
||||
self.assertIn("[exit 0]", result.content)
|
||||
self.assertEqual(result.exit_code, 0)
|
||||
|
||||
def test_argv_does_not_contain_setsid(self):
|
||||
"""setsid 已删(docker exec + setsid 会丢延迟 stdout,见 PROGRESS 2026-05-29)。
|
||||
未来 PGID kill 协议要做时改用 `setsid --wait` 或 wrapper,不能裸 setsid。
|
||||
"""
|
||||
executor, _, _ = make_executor()
|
||||
ctx = make_ctx(executor)
|
||||
proc = MagicMock()
|
||||
proc.communicate.return_value = ("ok", "")
|
||||
proc.returncode = 0
|
||||
captured = []
|
||||
|
||||
def _popen(argv, **kw):
|
||||
captured.append(argv)
|
||||
return proc
|
||||
|
||||
with patch("core.executor_docker.subprocess.Popen", side_effect=_popen):
|
||||
executor.call_tool("shell", {"command": "true"}, ctx)
|
||||
executor.call_tool("run_python", {"code": "pass"}, ctx)
|
||||
|
||||
self.assertEqual(len(captured), 2, "expected 2 Popen invocations")
|
||||
for argv in captured:
|
||||
self.assertNotIn("setsid", argv, f"setsid should not be in argv: {argv}")
|
||||
|
||||
|
||||
class TestRunPython(unittest.TestCase):
|
||||
"""run_python:tmp .py 落 user_root/.zcbot_tmp/<task_id>/,跑完 unlink。"""
|
||||
|
|
@ -287,8 +334,8 @@ class TestRunPython(unittest.TestCase):
|
|||
self.assertEqual(result.exit_code, 0)
|
||||
|
||||
argv = captured_argv[0]
|
||||
# 末尾形态:setsid python /workspace/.zcbot_tmp/<task_id>/<rand>.py
|
||||
self.assertEqual(argv[-3], "setsid")
|
||||
# 末尾形态:python /workspace/.zcbot_tmp/<task_id>/<rand>.py
|
||||
# (2026-05-29 删 setsid,见 _exec_python 注释)
|
||||
self.assertEqual(argv[-2], "python")
|
||||
self.assertTrue(argv[-1].startswith(f"/workspace/{TMP_SUBDIR}/{ctx.task_id}/"))
|
||||
self.assertTrue(argv[-1].endswith(".py"))
|
||||
|
|
|
|||
Loading…
Reference in New Issue