WuKongIM 持续发送 EOF 诊断：外部 I/O 压力窗口观测与内核计数器关联实证

持续高负载场景下反复出现的 sender_read: EOF，长期停留在"队列满是触发点、持久化等待是共现现象"的层面。本文以 WuKongIM 仓库中的专项诊断报告 2026-09-27-send-ban-io-window.md 为主体，完整还原其"外部 I/O 压力窗口"实验：如何在冻结二进制、不改产品的前提下，用独立的 Linux 内核计数器观察者区分 I/O 压力与 CPU/内存压力，把运行时区间与真实内核计数器关联，并最终在第二轮长跑中捕获到"节点写突增 → 2.25 秒窗口内 49.12% cgroup I/O full stall → WAL 与 SST compaction 同步重叠"的完整证据链。读完本文，你将掌握这套可复制的"观察者 + 飞行记录 + 离线关联"诊断方法、其证据边界，以及它如何把根因假设收窄到单一变量的下一次实验。

为什么需要"外部 I/O 窗口"：从飞行记录到内核计数器的证据缺口

诊断序列的起点是 飞行记录器捕获：在保留 5000 频道、4500 SEND/s、30 分钟目标的同档位诊断中，sustained-01 于 SEND 359.797 秒、1,619,089 次调用后复现 EOF，三个节点各暴露一次 async_dispatch_queue_full 关闭，permission busy 为零。四份 Go 1.25.11 飞行记录快照解析出 2,058,213 / 6,448,633 / 6,888,012 / 6,167,320 个事件，native 栈清晰区分了 WAL log-writer 同步与 SST flush/compaction 同步，例如节点 2 的 754.264ms Fdatasync 属于 RawRowWriter.Close -> compact1，而三个节点的 WAL writer 都出现一串约 119ms → 199ms → 390ms → 361ms 的同步间隔。

但这组证据存在一个致命盲区：重复出现的 WAL 同步等待与并发的 SST compaction/flush 同步等待同时发生，并不能证明 compaction 造成了 WAL 延迟——一个共享文件系统/虚拟机/设备事件可能同时拖慢两者。async_dispatch_queue_full 只说明关闭触发点是队列满，不解释相关 worker 为什么停止推进。因此在选择产品变更之前，必须把 I/O 压力从 CPU/内存压力中区分出来，并把运行时区间与真实内核计数器关联。这正是本文关联文档要解决的核心问题。

固定实验：保留冻结二进制，只新增独立内核计数器观察者

实验的第一原则是最小变更：保留前序飞行记录运行中完全相同的 product 与 harness 二进制（SHA-256 比对确认两者未变），仅新增一个独立的 Linux 计数器观察者（observer）。它等待四个任务所属 PID 的就绪清单（readiness manifests）全部出现后，以 250ms 周期顺序读取 21 个固定来源：

• 所属实验环境（owned lab）的 cgroup pressure / CPU / memory / I/O 计数器；
• Linux 虚拟机层面的全局 pressure、diskstats、vmstat 计数器；
• 四个清单 PID 各自的 io/stat。

观测语义被严格界定：全局 VM 来源不被声称是本次任务私有的；所有读取都是顺序进行，每条采样记录独立的错误状态与采样起止时间戳——没有任何一条采样是原子化的整机快照。

环形缓冲、峰值保留与显式失败语义

观察者进程保留 160 条采样（即最近约 40 秒） 以及最多 10 个峰值对，峰值按"非负的 cgroup I/O full-stall 微秒增量"排序。针对压力计数器的三种异常形态，语义是显式的：

• Reset（计数器重置）、missing（来源缺失）、malformed（格式异常）都被显式记录；
• 异常值绝不会被当作零参与统计，防止把"观测缺失"误读成"没有压力"。

环形缓冲只在四个进程全部就绪（即 cold prime 完成之后）才开始填充。观察者不写任何周期性采样文件，采集由三种条件之一终止：飞行捕获清单（flight-capture manifest）出现、精确的 runner 停止标记、或 40 分钟上限。

终止条件与资源边界

每个输入来源读取被限制在 32KiB，最终独占输出文件限制在 8MiB。runner 负责 join 观察者、保留其退出码并验证进程清理。文档明确强调：这些边界不会消除观察者自身的运行时开销——这是诊断工具，不是无副作用的探针。

测试先行与真实进程正向对照

实验延续了本系列一贯的"失败用例先行"纪律：失败清单与快速契约先于实现写出，RED 阶段在缺失 ring/pressure/read 辅助函数处失败；实现后环形缓冲回绕/淘汰、无效与重置压力、有界来源读取、峰值保留等契约全部通过，race 检查也通过。

随后是真实进程正向对照：25 频道 / 500 SEND/s / 10 秒测量窗口的公共 WKProto 场景，22.949 秒内完成 5,000 条消息，四份飞行捕获全部解析成功。观察者保留 41 条采样、零来源错误、零无效压力对；采样读取耗时中位数 0.293ms、最大值 0.837ms；最终计数器证据文件 647,335 字节；整个 runner 23.059 秒结束，清理后仅剩实验环境的 idle sleep 进程。文档特别强调：这些测量是正向对照（positive control），不是持续容量结论。长跑开始前，本任务可重建的 Go 编译缓存已被清空，且测量负载期间不允许任何编译、清理或解析活动与 SEND 重叠。

离线时钟精度修复：RFC3339Nano 与 34 万事件头的逐项核对

飞行记录中的 clock-snapshot 墙钟时间戳原本会丢失小数部分——已安装的 Go trace formatter 使用 time.RFC3339 格式。修复方式被刻意保持为隔离的离线解码器：仅在独立的离线 cmd/trace 解码器中将该常量改为 time.RFC3339Nano，Go 安装本身保持不变。在完整正向 harness trace 上，全部 342,702 个事件头在移除墙钟小数部分后与原解码器输出逐项一致。确切的源哈希、替换/构建命令与小数级时钟快照均被保留。

这里的关键判断是：该修复保留既有精度，而非制造精度。并且即使有了纳秒级时钟快照，250ms 周期、顺序执行的 /proc 读取间隔在关联采样时仍必须被尊重——计数器增量只能定位到 250ms 量级的窗口，不能精确定位到某一次系统调用或某一次物理盘操作。

第一轮长跑：磁盘保护中止、证据丢失与观察者修复

准备好的长跑命令为（保留 5000 频道、4500 SEND/s、30 分钟目标、256 个 hash Slots、128 个 append workers、gateway batch cap 32，以及既有的零拒绝/延迟门槛）：

python3 docs/reports/assets/send-ban-io-window-20260927/run.py sustained-01

第一次长跑始于 2026-09-27T11:26:31Z，在 748.538 秒后（含 168.757 秒 cold prime）被主机磁盘保护（host disk guard）中止。第 8 分钟报告 2,160,001 ACK/RECV、pending=0；第 9 分钟报告 2,427,944 ACK/RECV、pending=2,057。空闲空间从外部计时 +723.3s 时的 9.338GiB 骤降至 +738.4s 时的 4.863GiB。workload 与观察者均以 137 退出，OOMKilled=false。没有正常的捕获清单，也没有 I/O 窗口——这是一次被中止的观测，既不是复现的 EOF，也不是 R2 通过。文档明确要求：共享宿主机上空闲空间的变化原因未解释，不能仅凭这些读数归因于 swap、compaction 或产品本身。

受控 RED 复现证据丢失

更大的问题在于退出顺序：原磁盘保护在请求观察者环形缓冲之前就停止了容器，导致内存中的证据全部丢失。一个受控的进程级 RED 复现了这一点：仅将 runner 的空闲空间读数在 15 秒后改为 7GiB（无任何磁盘填充器），冻结二进制、25 频道 / 500 SEND/s，两个进程被杀后 I/O 与 trace 产物均缺失。

修复后的保护退出顺序与 GREEN 对照

修复后的保存顺序为：先记录保护触发时间、向观察者发信号并在 3 秒内 join，然后并发（带界定期限）请求四个既有的一次性记录器，最后才停止精确所属的容器；空闲空间低于 1GiB 时显式跳过 trace 写入。新增独立的 guard-capture.json 记录资源保护快照，与正常 capture.json 及正常通过语义严格分离。

匹配的 GREEN 对照被有意中止（workload 137、observer 1、runner_stop 标记），保留 16 条采样、零来源错误、四份完整快照；runner 总时长 25.591s，捕获 10.878ms。scheduler-profile 与全量 RFC3339Nano 解码对四个文件全部成功，事件计数为 harness 137,831，节点 708,328 / 767,521 / 641,593。这一轮只验证了测试过的关闭路径上的证据保全，不确立任何容量结论；快照写入发生在触发之后，因此被排除在触发前结论之外。期间一次因把隔离解码器包混入观察者导致的构建失败被保留并修复（显式选择观察者源文件），修复后快速契约与 race 全部通过。

严格离线的计数器/时钟契约同样先 RED（缺失实现）后通过全部六项检查：缺失/读取错误保留、重置处理、压力总量、磁盘字段单位/布局/设备选择、精确纳秒时钟换算、以及排除与捕获重叠的采样。这些是分析原语——对于已被中止的全规模运行，仍然没有可供分析的 I/O 窗口。三个停止夹具的日志、配置与文件清单在移除其精确任务所属的 test/plugin 目录前均被保存，长跑观察者身份与修复后的保护观察者身份分开保留。

第二轮 sustained-02：带完整内核与运行时证据的 EOF

修复观察者后，sustained-02 使用冻结的产品/harness 与来自 d48c6f8ed 的修复版外部观察者再次运行。它在 SEND 342.726 秒处失败：sender_read: EOF，已完成 1,542,268 次调用，pending=6,634，permission admission busy 保持为零；运行时指标记录节点 1 一次、节点 3 四次异步分发队列关闭（async-dispatch queue closure）。runner 总时长 534.670s，磁盘保护与 OOM 均未触发；harness 移除了自身夹具，只读终端检查确认精确夹具路径已不存在、仅剩容器的 idle sleep。这是一次诊断性失败，不是干净的 R2 资格或 R6 对照对。

失败概况与四份快照完整性

四份快照全部完整，gzip 往返校验与记录的原始 SHA-256 一致，scheduler 提取与全量 native 解码均成功。事件计数为 harness 1,986,034，节点 1 / 2 / 3 分别为 6,756,754 / 6,642,913 / 6,297,381。纳秒时钟快照偏移散布分别为 74 / 83 / 53 / 89ns；关联采用实际的上中位数整数偏移，保留散布，且不把它解读为经过认证的时钟误差上界。

观察者本轮采样 1,372 次，保留最终 160 条采样与 10 个全程峰值对，零来源错误、零无效压力对；最终输出 1,910,389 字节；保留的读取耗时中位数 0.325ms、最大值 1.943ms。有一对采样与捕获重叠，已从触发前结论中排除；所有 trace 文件写入均开始于下文使用的截止时刻之后。计数器读取是顺序的，250ms 增量无法识别具体的系统调用或物理宿主机磁盘操作。

故障前的 I/O 窗口：三个回顾区间的内核证据

以捕获起点为基准，故障前回顾窗口显示：

窗口（相对捕获起点）	Owned-cgroup 写入	Cgroup I/O full stall	VM block-flush 均值
−6.044s 至 −3.545s	27.88 MB/s	5.30%	0.127ms（4,883 次完成）
−3.047s 至 −2.296s	298.39 MB/s	10.01%	0.379ms（747 次完成）
−2.296s 至 −0.044s	111.32 MB/s	49.12%	17.28ms（125 次完成）

这三组窗口是观察后选取的解释性窗口，而非预先声明的统计比较。设备 254:0 从所属 cgroup 的 io.stat 中选出，其块计数器覆盖整个 Linux 虚拟机；block-flush 均值是累计完成刷新时间除以完成次数，不是 WAL fsync 测量，也不是物理盘饱和的断言。VM vda 的在途（in-flight）gauge 在这些采样中读到零（尽管有非零活动），因此未被用于推断队列占用。按 PID 的计数器显示写突增来自三个节点进程，而 harness 在捕获前为零记账写入；它们无法区分 WAL 字节与 SST 字节。

WAL 与 SST compaction 同步的分离证据

所选窗口的 CPU 节流时间与内存 PSI 均零增量，直接排除了 CPU 限流与内存回收假说。保留的运行时窗口中，节点已完成的可运行延迟达到 23.38 / 17.01 / 14.67ms；捕获前已完成的 WAL Fdatasync 间隔达到 173.79 / 193.76 / 222.11ms，而 SST compaction 的 Fdatasync 间隔更高，达 303.94 / 298.85 / 348.23ms。保留的 compaction 栈包含：

DB.compact1 -> compactAndWrite -> Runner.WriteTable -> fileBufferedWritable.Finish

WAL 栈包含 record.LogWriter.flushLoop -> syncWithLatency；gateway OnSendBatch 的等待在捕获前达到约 380–381ms。捕获之后单独的已完成间隔被保留但从这些最大值中排除。文档同时声明：top-160 间隔汇总是有界的选择，不是穷举的系统调用计数。

由此，第二轮添加了直接的内核证据：失败窗口包含一个紧随节点写突增之后的尖锐 I/O stall，并伴随重叠的慢 WAL 与 compaction 同步。它把下一个因果实验收窄到"SST compaction 写入竞争"；但它仍然不能证明那些写入造成了 WAL 延迟、不能识别宿主机固件/文件系统原因、也不能确立产品修复。后续任何单变量干预都必须保留真实同步、原始输入负载、准入/队列边界与已完成工作量，并且必须观察 compaction 债务（compaction debt），而非仅仅把 compaction 推迟到测试窗口之外。本轮探针没有修改任何产品设置或队列。

结论、预测与下一步：单变量干预要求

关联文档对假说给出了明确的判别预测：由共享 I/O 压力造成的持久化等待应与 I/O stall 及块队列变化对齐；CPU 节流或内存回收替代假说应有各自的计数器变化；而 compaction 竞争仍需在观测证据之后做单变量干预验证。同时重申验收纪律：

• 一次成功的带探针运行永远不能替代干净的 R2 资格或三对完整的 R6 性能对照；
• 缺失或截断的观测仍属证据不足；
• 不得扩大队列、放宽持久化保证，或仅凭系统调用墙钟时间断言内核根因。

可重复的离线分析命令与产物

在工作负载进入终态后，以下离线命令可重复执行（对应 sustained-02 运行）：

python3 docs/reports/assets/send-ban-io-window-20260927/check_capture.py sustained-02
python3 docs/reports/assets/send-ban-io-window-20260927/analyze_trace.py sustained-02
python3 docs/reports/assets/send-ban-io-window-20260927/analyze_io.py sustained-02
python3 docs/reports/assets/send-ban-io-window-20260927/correlate.py sustained-02

trace 分析器原样复用了前序记录器的区间算法，仅替换资产根目录与上述精度保留的离线解码器。io-intervals.json、io-stage-summary.json、correlation.json、原始计数器文本、选中的原始栈与完整压缩轨迹共同保存了这些结论的依据与边界。R2 与 R6 在该文档记录时仍保持未完成状态，后续的 compaction 限速对照 与 分片时间线 报告继续沿着这条单变量路径推进。

与 WuKongIM 源码的对应关系

I/O 窗口观测到的三个关键环节都能在仓库源码中找到落点：

1. gateway 分片队列容量：发送准入由 pkg/gateway/core/async_send.go 中的 sendExecutor 实现，逻辑分片数由 asyncSendLogicalShardCount 计算（每 worker 最多 4 个排序分片、受总容量除以最小分片容量约束），每分片容量为 asyncSendShardCapacity（向上取整的 总容量/分片数）。以夹具的 128 workers、131,072 总容量、batch cap 32 代入，得到 512 个逻辑分片、每分片 256 条队列；在 4500 SEND/s 均匀分摊到 25 条连接（每条约 180 条/秒）时，一个完全未排空的分片约有 256/180 ≈ 1.42 秒的积压余量——这与报告中"约 1.25 秒占用批次 + 队列精确涨至 256"的观察互相印证。
2. gateway 批次发送入口：internal/access/gateway/batch.go 的 OnSendBatch 依次完成预检、按会话排序、调用 h.messages.SendBatchEach 提交，并按会话顺序发布 ACK——这正是报告中 gateway handler 阻塞在 Router.submitResolvedGroupsEach -> message.SendBatchEach -> OnSendBatch 等待约 380–381ms 的位置。
3. 存储后端与相关配置：仓库 go.mod 锁定 Pebble v2.1.4，报告中 WAL 栈 record.LogWriter.flushLoop -> syncWithLatency 与 compaction 栈 DB.compact1 -> ... -> fileBufferedWritable.Finish 均来自该版本内部调用链。wukongim.toml.example 中与本次实验相关的默认值包括 channel_store_append_workers = 128、hash_slot_count = 256、runtime_async_send_workers = 1000、runtime_async_send_queue_capacity = 131072、default_session_async_send_batch_max_records = 128、send_timeout = "5s" 以及 storage_disk_slow_threshold = "1s"（用于在客户端超时前暴露慢同步的观测指标，只观测、不改变持久化行为）。实验夹具显式覆盖了其中 workers、队列与 batch cap，以复现 5000 频道 / 4500 SEND/s 的原定档位。

整套诊断的完整验收状态与功能/性能矩阵可对照 send-ban 验收核对报告，其 R2（30 分钟持续资格）与 R6（三对完整性能对照）在本文关联文档记录时仍未通过——这正是后续一系列单变量实验持续追查根因的前提。