agentscope-ai / agentscope-ai/AgentTeams

[Bug] copaw-worker 启动时 UnicodeDecodeError 读取 SOUL.md/AGENTS.md —— mc mirror 与 read_text 之间的文件稳定性 race

Open
#728 4 comments 0 reactions 1 assignee Claimed by @maplefeng-a View on GitHub
area:worker-runtime
Dominant language
Go
Stars
5.6k
Forks
692
Avg merge
5d 4h
Merged PRs (30d)
23

Description

### 摘要

`copaw-worker`(worker runtime,源码位于 `copaw/src/copaw_worker/`)在容器启动期间崩溃于以下代码路径:

```
copaw_worker/worker.py:123
(workspace_dir / name).write_text(src.read_text())
```

其中 `name` 为 `SOUL.md` 或 `AGENTS.md`。容器立即以 exit code 1 退出,未处理任何 Matrix 消息。Docker 重启策略会重新拉起容器;该 bug **会自愈** —— 我们观察到连续 8 次崩溃后第 9 次启动成功,之后已稳定运行 10+ 小时。

错误信息:`UnicodeDecodeError: 'utf-8' codec can't decode bytes in position N-N+1: unexpected end of data`,且 N 每次启动都会向后漂移几个字节。

根因看起来是 `copaw_worker/sync.py` 的 `mc mirror` 与紧接其后的 `read_text()` 之间存在 **文件稳定性 race**:mirror 步骤在文件**完整发布到目标路径之前**就报告了完成,因此后续的 `read_text()` 偶尔会观察到一个**末尾被截断**的中间状态——刚好把 multi-byte UTF-8 字符切成了两半。我们在 worker 稳定后手动读取**同一个文件**,可以无误地解码出完整内容,证明文件本身在稳定态下是合法 UTF-8。

### 环境

- 本地 docker 部署(Phase 1)
- Worker container:`hiclaw-worker-worker-streetlight-u002`
- Container Python:**3.11.15**
- Container locale:`UTF-8 ('en_US', 'UTF-8')`
- Container `sys.getdefaultencoding()`:`utf-8`
- Container `io.text_encoding(None)`:`'locale'`
- Worker package:`streetlight-worker 1.0.0`,包含 per-Worker `AGENTS.md`(22 563 bytes,合法 UTF-8)+ `SOUL.md`(2 444 bytes,合法 UTF-8)
- 存储后端:HiClaw 内置 MinIO(`hiclaw-storage`),通过 `mc mirror` 拉到 worker container 本地

### 复现

崩溃是 **transient**(非确定性)—— 每次容器冷启动都有概率命中 race,连续 docker 重启最终会成功。我们在一个 worker container 上观察到的模式:

| Start # | Timestamp | 结果 |
|--|--|--|
| 1 | 2026-04-27 04:13:23 | UnicodeDecodeError, position 22515 |
| 2 | 2026-04-27 04:18:24 | UnicodeDecodeError, position 22515 |
| 3 | 2026-04-27 04:23:25 | UnicodeDecodeError, position 22519 |
| 4 | 2026-04-27 04:28:26 | UnicodeDecodeError, position 22525 |
| 5 | 2026-04-27 04:33:27 | UnicodeDecodeError, position ~ |
| 6 | 2026-04-27 04:38:28 | UnicodeDecodeError, position ~ |
| 7 | 2026-04-27 04:43:28 | UnicodeDecodeError, position ~ |
| 8 | 2026-04-27 04:55:02 | UnicodeDecodeError, position 22531 |
| **9** | **2026-04-27 05:08:20** | **成功** —— 此后稳定运行 |

错误 position **始终位于 `AGENTS.md` 末尾附近内部**(文件大小 22 563 bytes,position 都落在最后 ~50 字节内),并 **逐次向后漂移几个字节**。worker 稳定后用 Python 读取**同一个文件**(`pathlib.Path("/root/.hiclaw-worker/worker-streetlight-u002/AGENTS.md").read_text()`)能正常返回 18 529 个字符无错误——说明问题不是文件内容本身,而是 read 时刻看到的瞬时状态。

最小复现步骤:

1. 构造一个 `AGENTS.md` 较大(如 ~22 KB 中文为主)的 HiClaw Worker package。英文短文件可能恰好不会让 race 落到 multi-byte sequence 边界上而隐藏。
2. `hiclaw apply -f ` 创建 Worker 资源。
3. `docker logs -f` 观察:容器会在 `Matrix re-login OK` 后约 1 秒内 exit (1),docker 重启它。
4. 重启 1 ~ 9 次后该文件内容稳定,bug 不再触发。

### 完整 traceback

```
[hiclaw-copaw-worker 2026-04-27 04:18:24] Starting copaw-worker: worker-streetlight-u002
2026-04-27 04:18:24,807 [INFO] copaw_worker.sync: mc cmd: /usr/local/bin/mc alias set hiclaw http://hiclaw-controller:9000 worker-streetlight-u002 ...
Pulling all files from MinIO...
2026-04-27 04:18:25,187 [INFO] copaw_worker.sync: mirror_all: full mirror completed from hiclaw/hiclaw-storage/agents/worker-streetlight-u002/
2026-04-27 04:18:25,214 [INFO] copaw_worker.sync: mirror_all: shared/ mirror completed from hiclaw/hiclaw-storage/shared/
... openclaw.json fetch + matrix password fetch ...
Matrix re-login OK (device: , token: )
╭───────────────────── Traceback (most recent call last) ──────────────────────╮
│ /opt/venv/copaw/lib/python3.11/site-packages/copaw_worker/cli.py:64 in _run │
│ ❱ 64 │ │ │ asyncio.run(_async_run()) │
│ /usr/local/lib/python3.11/asyncio/runners.py:190 in run │
│ ❱ 190 │ │ return runner.run(main) │
│ /usr/local/lib/python3.11/asyncio/runners.py:118 in run │
│ ❱ 118 │ │ │ return self._loop.run_until_complete(task) │
│ /usr/local/lib/python3.11/asyncio/base_events.py:654 in run_until_complete │
│ ❱ 654 │ │ return future.result() │
│ /opt/venv/copaw/lib/python3.11/site-packages/copaw_worker/cli.py:61 in │
│ _async_run │
│ ❱ 61 │ │ │ await worker.run() │
│ /opt/venv/copaw/lib/python3.11/site-packages/copaw_worker/worker.py:46 in │
│ run │
│ ❱ 46 │ │ if not await self.start(): │
│ /opt/venv/copaw/lib/python3.11/site-packages/copaw_worker/worker.py:123 in │
│ start │
│ 120 │ │ for name in ("SOUL.md", "AGENTS.md"): │
│ 121 │ │ │ src = self.sync.local_dir / name │
│ 122 │ │ │ if src.exists(): │
│ ❱ 123 │ │ │ │ (workspace_dir / name).write_text(src.read_text()) │
│ /usr/local/lib/python3.11/pathlib.py:1059 in read_text │
│ 1056 │ │ """ │
│ 1057 │ │ encoding = io.text_encoding(encoding) │
│ 1058 │ │ with self.open(mode='r', encoding=encoding, errors=errors) as │
│ ❱ 1059 │ │ │ return f.read() │
│ in decode:322 │
╰──────────────────────────────────────────────────────────────────────────────╯
UnicodeDecodeError: 'utf-8' codec can't decode bytes in position 22515-22516:
unexpected end of data
```

(每次崩溃 traceback 形态相同,只有最后 position 数字差几个字节。)

### 为什么我们认为这是文件稳定性 race

1. **错误 position 在文件内部、不超出文件末尾。** `AGENTS.md` 大小为 22 563 bytes,错误 position(22 515 / 22 519 / 22 525 / 22 531)均落在文件最后约 50 bytes 内。`unexpected end of data` 是 UTF-8 codec 在 multi-byte 字符序列中途撞到 EOF 的特征信号。
2. **稳定状态下文件内容是合法的。** worker 稳定后 hex dump 文件最后 80 bytes,全是规整的 3-byte UTF-8 序列(`e4 b8 8d` = U+4E0D「不」、`e3 80 82` = U+3002「。」等),失败 position 处的实际字节是合法 UTF-8 续字节。也就是说**写到磁盘的最终内容**是对的;崩溃时刻读到的是**未完成中间态**。
3. **Position 单调向后漂移。** 多次重启 position 是 22 515 → 22 519 → 22 525 → 22 531,逐次推进几个字节。如果是文件内容问题 position 应该是固定的;漂移强烈暗示 mirror 步骤把文件的"已发布大小"逐次扩大,但每次都还没到完整。
4. **重启数次后自愈。** 8 次崩溃后第 9 次启动成功,之后稳定 10+ 小时。如果 race 是确定性的每次都会触发;自愈说明非确定性,是典型 race 特征。
5. **`mc mirror` 报告 "completed" 在 `read_text()` 之前。** 日志显示 `mirror_all: full mirror completed` 紧接着就进入 `worker.py:123` 读文件,但 mirror 工具的"完成"语义可能仅指源端流读完,**不保证目标路径已经原子地发布稳定的完整内容**——典型实现可能是 truncate→分段写→close,或者上层文件系统(overlayfs / FUSE)对 cross-layer 可见性的延迟。

> **Note on POSIX semantics:** 我们最初怀疑过 fsync / page-cache flush 相关,但同进程后续 read 看 page cache 在 POSIX 下是有可见性保证的;fsync 主要解决 durability,不是同机 reader visibility。所以更准确的说法是 **mirror 步骤未原子发布稳定文件**,而不是"buffer 没刷新"。

### 建议的修复方向(按推荐顺序)

1. **在 `read_text` 上做 retry on UnicodeDecodeError + bounded backoff**(首选)。最贴合实际失败模式的修复:在 `worker.py:123` 处套一个最多 5 次、每次 100ms 的 retry,能完全吸收 race 而不改变成功路径的语义。
2. **mirror 到 temp 路径后 atomic rename / swap。** 在 `copaw_worker/sync.py` 的 mirror 步骤里:先 mirror 到 `*.tmp`,全部完成后 `os.replace(tmp, final)`,让 reader 永远只看到完整文件。这是从源头根治 race 的方式。
3. **stat-based 稳定性检查。** 在 read 之前轮询 `Path.stat()`,等到连续两次 stat 的 `(size, mtime)` 完全一致再 read。比 retry 多一层显式语义但代码量更大。
4. **不推荐:`errors="replace"`** —— 会静默腐蚀 prompt 文件,而 `SOUL.md` / `AGENTS.md` 的内容直接决定 agent 行为,绝不能用 lossy decode 兜底。

### 期望行为

`copaw-worker` 启动时不应依赖 `mc mirror` 返回时刻的具体语义 —— 无论底层用什么同步实现,都应该等到目标路径稳定后再读取,或者在 `UnicodeDecodeError` 上自动重试,而不是把"启动期 race"暴露为令人困惑的 UTF-8 解码错误(操作员看到这条错误第一反应是去查文件编码,而真正的原因和编码无关)。

### 我们排除的可能性

- **源文件编码本身没问题。** worker 稳定后 `pathlib.Path("/root/.hiclaw-worker/worker-streetlight-u002/AGENTS.md").read_text()` 在同一容器、同一 Python 版本下成功返回 18 529 个字符;唯一的差异是**何时读**。
- **不是 haopaw 侧的 concat / merge 问题**(这是我们最初的错误怀疑):失败 position 完全落在单个文件的范围内,不是两文件大小之和的边界。
- **不是 locale 问题。** `locale.getpreferredencoding()` 返回 `UTF-8`、`io.text_encoding(None)` 返回 `'locale'`(在该容器上 resolve 为 UTF-8)。我们也用显式的 `read_text(encoding="utf-8")` 测试过,行为一致。

### 影响

- 每次 worker 冷启动(首次 provisioning、容器重启等)都有一段降级窗口(通常几分钟到 ~10 分钟),期间 chat 是单向的:用户消息能到 Matrix,但 worker 不会回。自愈后恢复正常。
- 在慢盘 / overlayfs / 网络挂载的环境下 race 窗口更大;CI 或者高延迟存储更容易卡死。
- 操作员视角看到的是 `docker ps -a` 里 worker 不停 restart,没有明确的恢复路径或可读的错误指示,直到 bug 自愈。提供一条更明确的 "files not yet stable, retrying" 信息会大幅改善运维体验。

### 相关链接

- HiClaw repo(本 issue 提交位置):https://github.com/agentscope-ai/HiClaw
- QwenPaw(copaw-worker 包装的 agent runtime):https://github.com/agentscope-ai/QwenPaw —— 如果 maintainers 认为应转移此 issue,crashing 代码在 `copaw_worker/worker.py:123`,目前在 HiClaw 仓内。

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.