Skip to content

fix(acp): add timeout for filesystem semaphore acquisition to prevent agent hangs - #1128

Open
ana52070 wants to merge 1 commit into
spacering-net:mainfrom
ana52070:fix/acp-fs-hang-prevention
Open

ana52070 wants to merge 1 commit into
spacering-net:mainfrom
ana52070:fix/acp-fs-hang-prevention

Conversation

@ana52070

Copy link
Copy Markdown
Contributor

PR 标题建议

fix(acp): add timeout for filesystem semaphore acquisition to prevent agent hangs


PR 正文

问题

在使用 Antigravity 等基于 ACP 协议的 Agent 进行编码开发时,Agent 经常会在即将完成任务、甚至所有回答文本与代码均已完整流式输出到界面的时刻发生卡死:

  • 表象:UI 持续显示 正在响应…,速率平滑归零至 0.0 tok/s,计时器无限递增,对话无法结束(未收到 turn_end / PromptResponse)。
  • 根本原因:
    1. 在即将收尾时,Agent 往往会发起并发只读工具调用(如通过 ACP fs/read_text_file 调用 client_view_file 读取配置文件或代码进行校验)。
    2. 在 Codeg 端的 src-tauri/src/acp/file_system_runtime.rs 中,read_text_file 和 write_text_file 入口处获取并发信号量:
      let _permit = self.io_semaphore.clone().acquire_owned().await...;
      该信号量获取没有任何超时机制(虽然底层文件 IO 有 30s 超时,但获取锁本身可无限期阻塞)。当突发并发请求激增或 permits 排队积压时,请求会被永久挂起。
    3. Antigravity 等 Agent 内部 harness 事件循环要求所有并发 Step 必须全部结算(is_idle == true 且队列清空)才会返回 turn_end。由于悬挂的只读请求永远未返回,导致 Agent 即使输出完毕也无法完成轮次,形成死锁。

改动

  1. 新增信号量获取超时保护:

    • 在 src-tauri/src/acp/file_system_runtime.rs 中新增超时常量 FS_ACQUIRE_TIMEOUT = Duration::from_secs(15)。
    • 实现辅助方法 acquire_io_permit(&self, operation: &'static str),对 io_semaphore.acquire_owned() 增加 tokio::time::timeout 保护。
    • 超时后生成明确的 FileSystemRuntimeError::Internal(format!("{operation} timed out waiting for filesystem permit after {}s", FS_ACQUIRE_TIMEOUT.as_secs())) 错误信息。
    • 在 read_text_file 与 write_text_file 入口处统一使用 acquire_io_permit。
  2. 保障 RPC 错误完整闭环回传:

    • 确认当超时发生时,错误能够通过 FileSystemRuntimeError::into_rpc_error 正确转换为 JSON-RPC ErrorCode::InternalError 并返回给 Agent,使 Agent 端的 Step 标记为失败并立即结算,不再挂死。
  3. 单元测试与回归用例:

    • 新增 read_times_out_when_permits_exhausted 与 write_times_out_when_permits_exhausted 两个单元测试,全面验证全部并发许可证被耗尽时超时行为的正确性及释放后的恢复能力。

测试

  • 本地针对性回归测试:
    • cargo test --no-default-features --features server-bin --lib acp::file_system_runtime::tests 全部通过(41 passed; 0 failed)。
  • 本地规范与构建检查:
    • cargo check --features test-utils:PASS(0 errors, 0 warnings)。
    • cargo clippy --all-targets --features test-utils --jobs 4 -- -D warnings:PASS(0 warnings)。
  • CI 预检:
    • 代码变更仅限后端 ACP 运行时通道容错,已在干净独立的 Git Worktree(codeg-acp-turn-hang-prevention)上自检完成,提交记录符合 Conventional Commits。

@xintaofei

Copy link
Copy Markdown
Collaborator

@ana52070 感谢你提这个 PR!Antigravity 回合结束时卡在「正在响应…」的现象描述得很清楚,acquire_io_permit 把错误经 into_rpc_error 回给 agent 的思路也是对的,测试用 start_paused 避免真等 15 秒也很细心。

不过这一版我们先不合并。原因是:按 codeg 当前处理 ACP 请求的调用方式,同一个连接上的 fs 回调是串行执行的,8 个许可不会被并发的 fs 请求耗尽,新加的 15 秒许可等待超时也就没有触发的条件。这样它不会改变实际运行时的行为,也就解决不了你遇到的卡死。卡死本身我们很想查清楚,下面把理由和我们需要的信息都列出来。

概要

  1. 同一个连接上的 fs 请求是逐个处理的
  2. 所以在当前调用路径下,许可不会被耗尽,新超时不会触发
  3. 现有的 30 秒超时限制的是对阻塞任务的等待,消息排队时间仍会累加
  4. 新测试为什么能通过
  5. 卡死更可能出在别处:需要的信息
  6. 如果确认是 fs 回调拖住了连接
  7. 一个小问题

1. 同一个连接上的 fs 请求是逐个处理的

codeg 用的 ACP SDK 是 agent-client-protocol 3.4.0。它的文档写明:每个连接有一个 dispatch loop,on_receive_request 注册的回调在这个 loop 里运行,loop 会等当前回调完成后才处理下一条消息(ordering.rs#L7-L21)。实现上也是这样:收到的消息逐条 await 分发(incoming_actor.rs#L169-L180),分发时直接 await 注册的回调(handlers.rs#L123-L130)。

codeg 这边,每个连接新建一个自己的 FileSystemRuntime(connection.rs#L8623),用到它的只有 fs/read_text_file 和 fs/write_text_file 两个回调,两者都在回调里直接 await 运行时的方法,没有 cx.spawn / tokio::spawn(connection.rs#L8783-L8812)。除了测试里直接拿许可之外,生产代码中 io_semaphore 没有其他获取方。

2. 所以在当前调用路径下,新超时不会触发

许可数、许可等待超时、IO 超时和慢日志阈值分别是 8、15 秒、30 秒和 200 ms(常量定义)。

结合第 1 节:agent 即使并发发出多个 fs/read_text_file,它们在 codeg 这一侧也是在消息层面排队、一个接一个进入回调的,同一个运行时同一时刻最多只有一个请求持有许可。在当前这两个生产回调的串行调用路径中,8 个许可不会被并发 fs 请求耗尽,因此也就没有因许可竞争而等满 15 秒的条件,acquire_io_permit 里的超时分支走不到。

3. 现有 30 秒超时限制的是什么

许可是在 async 函数的栈帧里持有的,没有交给阻塞线程(读请求、写请求)。run_blocking_with_timeout 对 spawn_blocking 的 JoinHandle 套了 30 秒超时(file_system_runtime.rs#L1069-L1092),超时后函数返回、许可随之释放,agent 收到一个错误响应,错误数据里是 fs/read_text_file timed out after 30s 这样的文本。(超时的那个阻塞任务本身可能还在后台跑,但它不持有许可。)

在运行时正常调度、计时器正常推进的前提下,现有超时会在等待阻塞任务约 30 秒后返回错误。但这不是请求从到达到返回的总耗时上限:按 SDK 文档,回调运行期间这个连接不处理新消息,所以请求进入回调前还可能在等前面的消息,多个慢 fs 请求的等待时间也会叠加。因此光看卡住多久,不足以判断是不是 fs 相关,还需要结合日志里的时间点。

4. 新测试为什么能通过

两个新测试先在测试里手动拿走全部 8 个许可(file_system_runtime.rs#L3189-L3197、#L3236-L3244),再验证超时、错误码转换和释放后的恢复。这些行为本身没问题,但「8 个许可都被占着」这个前提在当前生产调用路径中达不到(见第 2 节),所以测试证明的是超时分支能用,而不是复现了卡死。

5. 卡死更可能出在别处:需要的信息

你描述的现象(文本已经输出完、速率归零、计时器一直走)我们想继续查。方便的话请提供:

  • codeg 版本、桌面版还是服务器版;Antigravity 的版本
  • 大概多久复现一次,卡住时界面上最后一个工具调用是什么、它的状态
  • 卡住时间点前后的 codeg 日志:设置 → 运行日志。
    • 下面这类慢日志是「信息」级别,默认级别就会记录;请确认采集级别、按模块覆盖和查看筛选没有把它屏蔽掉。
    • 读文件的日志格式是 [ACP] fs/read_text_file slow path=… elapsed_ms=…,写文件是 fs/write_text_file slow(file_system_runtime.rs#L1348-L1357)。计时从取得许可后开始,在阻塞任务返回或等待超时后才记录,达到 200 ms 才输出,不包含之前的消息排队。
    • 如果卡住时间点附近有 elapsed_ms 接近或超过 30000 的记录,说明那次 fs 请求在取得许可后等了很久(可能是文件 IO 本身,也可能是阻塞线程池排队或调度延迟),这就值得顺着第 6 节继续查。
    • 如果卡住已经远超 30 秒,在确认日志完整、没有被过滤的前提下,附近仍没有接近或超过 30000 的记录,那就不支持「某一次 fs 回调一直在等阻塞任务」这个解释。不过很多次较短的 fs 回调仍可能累积出很长的消息排队,单次不到 200 ms 时甚至不会留下慢日志,所以还要结合 fs 请求的数量和时间线来看。
    • 日志里会有本机路径,贴之前请删掉你不想公开的部分。

另外,如果你装上这个补丁后实测确实不再卡住,也请告诉我们复现步骤和前后对比,这会是很重要的线索。

6. 如果确认是 fs 回调拖住了连接

如果进一步确认,fs 回调里等待工作完成确实延迟了后续消息的分发,可以考虑让回调通过 cx.spawn 启动任务后尽快返回,由任务在完成后回传结果。这样多个 fs 请求才会真正并发执行;到那时是否会出现许可竞争、是否需要像你这样的许可等待超时,要在新的调用方式下再评估。实现时还要考虑请求顺序、并发写入、连接关闭或取消,以及错误回传。这只是一个待验证的调查方向,单凭慢日志还不足以确定需要这样改。

7. 一个小问题

新加的 acquire_io_permit 和两个测试还有几处格式与 rustfmt 不一致,下次提交前跑一下 cargo fmt 就好。

如果你那边有我们没考虑到的路径(比如抓到过请求真的卡在等许可上的证据),欢迎直接指出,我们再一起看。再次感谢!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants