写入全部报成功,记录却少了近千条
agentwatch 守护进程在一万条记录的压力测试中仅保留 9016 条,但调用方均收到成功结果。文章指出,后台全量校验与写入热路径争用同一把锁,是排查这一静默丢失问题的关键。
AI 深度解读
一次持续负载测试,哈希链完整,verify-store 检查通过,p99 延迟只有 0.36 ms。可作者数了一下记录:发送 10,000 条,只留下 9,016 条。系统看起来健康,数据却少了近一成。
问题出在后台校验线程:它拿着写入线程需要的锁,读取整个文件,再重新计算整条哈希链。这个案例值得读,不只是因为它展示了怎样缩短临界区,还因为第一次修复随即引入了新的竞态。性能问题和数据一致性,得一起处理。
写入慢,可能是后台任务占着锁
agentwatch 是 agentic-suite 中的 AI Agent 安全记录工具,支持不依赖特定运行框架的接入方式。它的 recorder daemon 有两条关键线程:Accept 接收 hook 发来的 Unix socket 消息,完成读取、标准化和追加;Sweeper 每隔 5 秒重新加载存储文件,校验整条哈希链,发现篡改就把健康状态改为 degraded。
哈希链让后一条记录关联前一条记录的哈希,用来发现历史内容被改动。但校验链完整,不代表应该到达的记录全部到达。
两条线程都要获取 store._lock。下面是原来的 refresh(),它负责重新读取并验证存储:
def refresh(self):
with self._lock:
self._entries = self._load() # read the ENTIRE file from disk
self._recount()
return self.verify() # recompute EVERY hash — O(n)
要看的是 with self._lock: 的范围:磁盘读取、计数和逐条验哈希,全在锁里面。文件越大,写入线程等得越久。
作者测得,1,000 条记录时校验约需 11 ms,5,000 条时为 56 ms,10,000 条时约为 116 ms。一次 10k-send 测试末尾,存储里约有 20,000 条记录,单次校验达到 242 ms。原文没有解释这 20,000 条与本轮 10,000 次发送的关系。
写入被挡住后,连接进入 listen backlog 等待。连接超时设为 1 s;send() 失败会返回 False,但 hook 采用发出后不等待处理结果的方式,Agent 忽略返回值,也不会重试,daemon 没有记录这些发送失败。
因此,标题里的「报告成功」需要拆开理解:原文展示的是调用方忽略失败,整体测试仍然报绿,没有展示每次失败写入都收到成功确认的协议证据。
把队列调大,为什么只救回来一部分
作者最初判断,单线程 Accept 处理不过来,于是把 server.listen(128) 改为 server.listen(512)。
结果从 9,016/10,000,约 90%,提升到 9,499/10,000,约 95%。丢失比例从约 10% 降到约 5%,但仍有约 500 条没留下。作者为这次误判花了两轮完整测试。
增加排队空间确实可能缓解突发拥堵,但无法缩短锁占用。请求可以多等一会儿,等待预算却仍然受超时限制。
先区分处理能力不足和处理线程被阻塞,再决定要不要扩队列。
不过,原文给出的丢失数量推导并不充分。作者按约 200 条/秒估算,242 ms 内约有 48 次追加等待;100 秒内运行 20 次校验,得到 20 × 48 = 960 次阻塞,并列出另一轮结果:交付 9,036 条,丢失 964 条。
阻塞次数不能直接当成丢失次数。48 小于 backlog 的 512 个槽位,242 ms 也短于 1 s 超时。要解释这些等待如何变成连接超时,还需要队列已有积压、流量突发或恢复速度等证据。改锁后测试通过,支持锁竞争是关键因素;但这段算式不能独立证明全部丢失过程。
把重活移出锁,还要防止旧快照覆盖新状态
作者最终把文件读取和校验放到锁外,只在更新内存状态时加锁。下面是包含后续竞态修复的版本:
def refresh(self):
entries = self._load() # disk read — no lock
status = self._verify_entries(entries) # O(n) verify — no lock
with self._lock: # O(1) reference swap
if len(entries) >= len(self._entries):
self._entries = entries
self._recount()
return status
关键是 if len(entries) >= len(self._entries):。这行保护来自第一次移锁后暴露的问题:下一轮测试报出 agentsec-agentwatch: chain broken at seq 815。
读取文件不再持锁,append() 就可能同时写入。假设磁盘快照只读到 815 条,内存已经追加到 820 条,如果直接用旧快照覆盖内存,下一次追加就会重新使用 seq 816。磁盘上已有 seq 816,序号重复,链随之损坏。
长度判断阻止较短快照覆盖较新的内存状态。旧快照仍会接受校验,本轮未读到的内容留给下次 Sweeper 处理。
这段修复依赖追加式存储的特点:旧快照通常更短。它不是所有并发数据结构都能套用的规则。
另外,引用替换可以是 O(1),但 _recount() 仍在锁内。原文没有给出它的实现,不能仅凭这段代码确认整个临界区都是 O(1)。作者报告修复后写入等待降至微秒级,最终交付 10,000/10,000,p99 为 0.36 ms,verify-store 通过;修复进入 agentwatch v0.1.0,并以 10k 持续负载测试防止回归。
我的判断
我认同作者的排查方向:后台任务是否影响请求处理,要看共享资源和锁占用,不能只看线程名字。校验总耗时仍是 O(n),让它少占着写入需要的锁,就可能显著改善系统表现。
但「成功」必须有明确边界。连接建立、消息发送、daemon 接收和持久化完成,是不同阶段。原文没有交代确认协议,也没有说明 p99 的计时范围以及失败请求是否进入统计。只统计成功请求的延迟,无法说明丢失请求经历了什么。
长度保护也有适用前提。它能挡住较短快照回退,却不能单独证明等长快照更新、更长快照正确,或并发读取不会碰到未写完的记录。这些边界,原文没有说清。
和继续扩 backlog 相比,缩短锁占用更贴合这次故障证据;和增量校验相比,它仍保留每 5 秒全量读取、校验的成本。作者没有提供不同方案的对照数据,因此不能把这次成功推广成普遍最优解。
能拿来做什么
- 给持续负载测试加入发送数与最终记录数核对,并保留唯一标识检查重复和缺口。链校验、延迟分位数和数据完整性要分别验收。
- 检查 Node 服务调用的本地 daemon,以及日志写入、索引刷新等后台任务,测量数据达到当前 10 倍时的锁占用时间,再决定是否扩大队列。
- 为 AI 编程 hook 明确 send() 返回 False 后的处理方式,并让失败可见。若准备重试,要同时考虑重复记录,不能只补一个重试循环。
- 把耗时操作移出锁时,补查旧快照覆盖新状态的竞态。追加式存储可以参考长度保护,其他结构需要依据自身更新规则设计判断条件。