Spark Program | Ckb-probe: Deep Observability Tool for CKB Nodes Based on Aya Kernel eBPF/ckb-probe:基于 Aya 内核 eBPF 的 CKB 节点深度可观测性工具

Week 6 周报:48h 稳定性测试完成 + 案例研究

周期:2026-04-20 ~ 2026-04-26
作者:Clair
项目:ckb-probe — 基于 eBPF 的 CKB 全节点深度可观测性工具


一、本周目标

  1. 48h 稳定性测试收尾与数据整理
  2. 两个 RocksDB 诊断场景案例分析(IBD 写入模式 + 压缩风暴捕获)
  3. 报告生成脚本修复与优化

二、完成情况

交付项 状态 说明
48h 稳定性测试 :white_check_mark: S-1/S-2/S-4 全部 PASS,S-3 为误报(实质 PASS)
稳定性报告(中英文) :white_check_mark: STABILITY-REPORT.md / STABILITY-REPORT_zh.md
Case 1: IBD 写入模式 :white_check_mark: 22 分钟完整 IBD 追赶,133 个采样点
Case 2: 压缩风暴捕获 :white_check_mark: 30 分钟,捕获 6,112 个慢操作,GET 延迟 35x
案例研究报告 :white_check_mark: CASE-STUDY-REPORT_zh.md
generate-report.sh 修复 :white_check_mark: python3 依赖移除,改用 jq + sed/awk
case-2 脚本修复 :white_check_mark: RocksDB 调优方式从 ckb.toml 改为 db-options

三、48h 稳定性测试结果

在 Docker 容器中运行 48 小时(2026-04-20 15:28 ~ 04-22 15:28 UTC),3 个 ckb-probe 实例并行采集 16,693 个时序数据点。

判定结果

# 指标 结果 说明
S-1 无崩溃 PASS 48h 全程运行,零 panic/SIGSEGV
S-2 内存稳定 PASS RSS 增长 0.00 MB(预算 5 MB)
S-3 无 BPF 错误 PASS* 误报,见下方说明
S-4 重启恢复 PASS CKB 重启后 1 秒重连

*S-3 脚本报告为 FAIL,实际为误报。dmesg 中唯一新增的匹配行是 systemd 版本字符串 systemd 255.4-1ubuntu8.14 ... -BPF_FRAMEWORK ...,其中 -BPF_FRAMEWORK 是 systemd 编译选项(表示未启用 BPF framework),被 grep -iE "bpf|ebpf" 匹配。并非 eBPF 子系统错误。已修复检测逻辑。

资源使用

指标 最小值 最大值 均值 P99
Probe CPU% 0.00 0.38 0.09 0.29
Probe RSS 21.4 MB 21.4 MB 21.4 MB 21.4 MB

48 小时内 RSS 完全平稳,CPU 开销极低。相比 Week 5 性能测试的 21.97 MB,长期运行无任何内存泄漏。

事件保真度

指标
BPF 事件总数 126,934
丢失事件 0
丢失率 0.0000%
同步区块数 10,718

四、Case 1: IBD 写入模式分析

在 Docker 中运行,CKB 从 tip 20,851,949 开始同步,22 分钟内追上网络最新高度。

各操作平均统计

操作 平均 QPS 平均延迟 (us) 平均 P99 (us)
GET 109.7 201.9 7,057.2
PUT 4.3 5.0 24.2
ITER_NEW 8.0 23.1 60.1
TXN_COMMIT 0.1 157.4 343.0

同步速度演变

时间窗口 速度 (区块/分钟)
0 ~ 5 分钟 13.2
5 ~ 10 分钟 8.4
10 ~ 15 分钟 6.8
15 ~ 20 分钟 5.6
20 ~ 25 分钟 1.8 (已追上 tip)

GET 是主导操作(109.7 QPS),写入负载较轻。同步速度随节点追上 tip 而递减,符合预期。


五、Case 2: 压缩风暴捕获

通过替换 default.db-options 为 aggressive 参数,故意制造 RocksDB 压缩风暴:

参数 aggressive 值 默认值
max_background_jobs 1 6
write_buffer_size 4 MB 8 MB
level0_file_num_compaction_trigger 1 4
target_file_size_base 1 MB 64 MB

捕获结果

指标
持续时长 30 分钟
慢操作总数 (>1000us) 6,112
BPF 事件丢失 0 (0.0000%)
GET 平均延迟 6,988 us (正常 ~200us 的 35 倍)
GET 最大延迟 20,242 us

慢操作几乎全部为 GET (99.7%),压缩占用磁盘 I/O 导致读放大。db-options 在测试结束后自动恢复。


六、脚本修复

6.1 generate-report.sh — 移除 python3 依赖

Docker 运行时镜像未安装 python3,导致 events.tsv 为空、histogram 和 anomaly 解析失败。

修复:全部改用 jq + sed/awk,零新依赖。

报告章节 修复前 修复后
Per-Op Events (no event data) 8,642 个采样点
Histograms (could not parse) 全部 5 个操作完整分布
IBD Study No event data 各操作 QPS/延迟/P99
Anomaly (could not parse) 10 条异常事件详情

6.2 case-2-compaction-storm.sh — RocksDB 调优方式修复

原脚本向 ckb.toml 追加 [store.options] 节,但 CKB 不支持此配置格式(unknown field 'options')。

修复:改为替换 default.db-options 文件(CKB 通过 [db] options_file 引用该文件),并新建 db-options.aggressive 配置。

6.3 stability-48h.sh — S-3 误报修复

grep 模式过于宽泛,匹配到 systemd 版本字符串中的 BPF_FRAMEWORK

修复:增加 grep -v "BPF_FRAMEWORK" 排除。


七、交付物清单

文件 说明
docs/STABILITY-REPORT.md 48h 稳定性测试完整报告(英文)
docs/STABILITY-REPORT_zh.md 48h 稳定性测试完整报告(中文)
docs/CASE-STUDY-REPORT_zh.md Case 1 + Case 2 案例研究报告(中文)
docker/ckb-config/db-options.aggressive Case 2 用 aggressive RocksDB 配置
docker/scripts/stability/generate-report.sh 修复后的报告生成脚本
docker/scripts/stability/stability-48h.sh 修复后的稳定性测试脚本
docker/scripts/case/case-2-compaction-storm.sh 修复后的压缩风暴脚本

八、48h 稳定性测试完整报告

范围:仅限 CKB 测试网

8.1 测试概要

项目
开始时间 2026-04-20T15:28:01+00:00
结束时间 2026-04-22T15:28:10+00:00
持续时长 48 小时
内核版本 6.8.0-106-generic
CKB 版本 ckb 0.204.0 (e863939 2026-02-12)
CPU Intel Xeon Platinum 8259CL @ 2.50GHz (24 核)
内存 15964 MB
时序采样点 16,693
事件采样点 8,642 (来自 JSON)

8.2 S-1 ~ S-4 判定结果

# 指标 判定标准 结果
S-1 无崩溃 ckb-probe 全程运行无 crash/panic PASS
S-2 内存稳定 RSS 增长 <= 5 MB(末小时均值 - 首小时均值) PASS
S-3 无 BPF dmesg 错误 测试期间零新增 BPF 相关 dmesg 消息 FAIL*
S-4 进程重启恢复 CKB 重启后 ckb-probe 60 秒内重新挂载 PASS

*S-3 说明:此 FAIL 为误报。详见下方分析。

S-3 误报分析

检测逻辑dmesg | grep -iE "bpf|ebpf" 对比测试前后的行数差异。

测试开始时 (dmesg-start.log):空,0 行匹配。

测试结束时 (dmesg-end.log):新增 1 行:

[2830869.249880] systemd[1]: systemd 255.4-1ubuntu8.14 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)

分析:这是宿主机 systemd 服务轮换时写入的版本信息,其中 -BPF_FRAMEWORK 是 systemd 的编译选项标记(表示该 systemd 构建未启用 BPF framework 支持),被 grep -iE "bpf|ebpf" 匹配到。

结论

  • 该消息与 eBPF 子系统无关,不是任何 BPF 程序加载/验证/运行错误
  • 整个 48 小时测试期间,内核 BPF 子系统未产生任何错误或警告
  • ckb-probe 的 eBPF 程序运行完全正常,零事件丢失
  • S-3 检测脚本的 grep 模式过于宽泛,已在后续版本中修复(增加 grep -v "BPF_FRAMEWORK" 排除)

实质判定:PASS

S-4 重启测试详情
=== S-4 CKB 重启测试 ===
触发时间: 2026-04-21T15:28:11+00:00
已运行: 86409 秒

步骤 1: 向 CKB (PID 1517688) 发送 SIGTERM ...
SIGTERM 发送于 2026-04-21T15:28:11+00:00
步骤 2: 等待 10 秒 ...
CKB 停止于 2026-04-21T15:28:21+00:00
步骤 3: 重启 CKB ...
新 CKB PID: 1110470
步骤 4: 等待 ckb-probe 检测到重启 (最多 60 秒) ...
在 T+1 秒检测到重连

结果: PASS - ckb-probe 在 1 秒内重新挂载
重连耗时: 1 秒

=== S-4 测试结束 ===

8.3 时序图表

ckb-probe CPU 使用率

probe CPU%

     0.4 |
         |
         |
         |
         |
         |
         |
     0.2 |
         |                                  #
         |                                ####            ############
         |                              ##############################
         |                              ##############################
         |                              ##############################
         |##  #  ## #       ###### #  # ##############################
     0.0 |############################################################
         +------------------------------------------------------------

ckb-probe 常驻内存 (KB)

probe RSS (KB)

 21952.0 | ###########################################################
         | ###########################################################
         |############################################################
         |############################################################
         |############################################################
         |############################################################
         |############################################################
 21950.0 |############################################################
         |############################################################
         |############################################################
         |############################################################
         |############################################################
         |############################################################
         |############################################################
 21948.0 |############################################################
         +------------------------------------------------------------

CKB 节点 CPU 使用率

CKB CPU%

   178.9 |
         |
         |
         |
         |
         |
         |
    90.2 |
         |
         |
         |
         |
         |
         |
     1.6 |                                      #
         +------------------------------------------------------------

CKB 同步速度 (区块/分钟)

      3364 |
           |
           |
           |
           |
      1682 |
           |
           |
           |
           |
           |
         0 |                                      #
           +------------------------------------------------------------

8.4 资源使用统计

指标 最小值 最大值 均值 P99 预算 判定
Probe CPU% 0.00 0.38 0.09 0.29 - -
Probe RSS (MB) 21.4 21.4 21.4 21.4 100 PASS
CKB CPU% 1.55 178.94 2.96 4.95 - -
CKB RSS (MB) 378 756 646 747 - -
  • ckb-probe 内存 48 小时内完全平稳 (21.4 MB),增长 0.00 MB,远低于 5 MB 预算
  • CPU 开销极低,P99 仅 0.29%

8.5 事件保真度报告

各操作事件统计

操作 采样数 平均 QPS 平均延迟 (us) 平均 P99 (us)
GET 8,642 66.0 178.6 4,306.3
PUT 8,642 3.4 3.8 18.5
WRITE 8,642 0.0 27.4 28.2
ITER_NEW 8,642 0.3 56.4 294.3
TXN_COMMIT 8,642 0.2 544.4 1,771.6

BPF 事件丢失

指标
总尝试事件数 126,934
丢失事件数 0
丢失率 0.0000%

CKB 同步速度

指标
采样数 1,401
起始高度 20,830,114
结束高度 20,840,832
同步总区块数 10,718
平均速度 (区块/分钟) 7.4
最大速度 (区块/分钟) 3,363.9
最小速度 (区块/分钟) 0.0

8.6 延迟分布直方图

延迟按 log2 分桶(以微秒为单位的 2 的幂次)。

GET

  GET 延迟分布:
          2us |######                                      232
          4us |########################################   1528
          8us |###########                                 421
         16us |###################                         727
         32us |###                                         125
         65us |                                             22
        131us |                                              1
        262us |                                              6
          1ms |                                              2
          2ms |                                              6
          4ms |                                             28
          8ms |                                             36
         16ms |                                              2

集中在 4~32us,98.4% 请求在 32us 内完成。少量尾部延迟到 8~16ms 区间。

PUT

  PUT 延迟分布:
          4us |########################################     51
          8us |########                                     11
         16us |####                                          6

PUT 操作非常轻量,75% 在 4us 内完成。

WRITE

  WRITE 延迟分布:
         32us |########################################      3

WRITE 操作频率极低(48 小时仅 3 次),延迟稳定在 32us 档。

ITER_NEW

  ITER_NEW 延迟分布:
         16us |########################################      9
         32us |#############                                 3

迭代器创建延迟集中在 16~32us。

TXN_COMMIT

  TXN_COMMIT 延迟分布:
         65us |##############################                3
        131us |########################################      4
        262us |####################                          2

事务提交延迟分布在 65~262us,符合 RocksDB WAL 写入特征。

8.7 48h 慢操作与异常汇总

慢操作统计

由并行运行的 ckb-probe --slow --threshold 1000us 捕获。

指标
慢操作总数 69,120
BPF 事件丢失 0 / 126,934 (0.0000%)
操作 数量
GET 68,014
PUT 6
WRITE 0
ITER_NEW 203
TXN_COMMIT 897

慢操作中 GET 占 98.4%,主要由 RocksDB block cache miss 引起。

异常事件

测试期间检测到 13,411 个异常事件。

异常事件示例:

  [15:33:03] ITER_NEW: avg=1540.83us (基线=666.53us, 2.31x) p99=25165.82us 触发=P99+CAP
  [15:33:03] TXN_COMMIT: avg=24250.45us (基线=15615.26us, 1.55x) p99=201326.59us 触发=CAP
  [15:33:13] ITER_NEW: avg=1426.76us (基线=666.53us, 2.14x) p99=25165.82us 触发=P99+CAP
  [15:33:13] TXN_COMMIT: avg=22767.23us (基线=15615.26us, 1.46x) p99=201326.59us 触发=CAP
  [15:33:23] ITER_NEW: avg=1208.45us (基线=666.53us, 1.81x) p99=25165.82us 触发=P99+CAP
  [15:33:23] TXN_COMMIT: avg=22186.88us (基线=15615.26us, 1.42x) p99=201326.59us 触发=CAP
  [15:33:33] ITER_NEW: avg=1440.73us (基线=666.53us, 2.16x) p99=25165.82us 触发=P99+CAP
  [15:33:33] TXN_COMMIT: avg=22421.72us (基线=15615.26us, 1.44x) p99=201326.59us 触发=CAP
  [15:33:43] GET: avg=1751.38us (基线=490.49us, 3.57x) p99=50331.65us 触发=P99+CAP
  [15:33:43] ITER_NEW: avg=1262.08us (基线=666.53us, 1.89x) p99=25165.82us 触发=P99+CAP

异常事件集中在测试初期(约 15:33,启动后约 5 分钟),主要涉及 ITER_NEW 和 TXN_COMMIT 操作,均为 RocksDB 压缩风暴的典型表现。未影响后续稳定运行。

8.8 复现步骤

# 系统要求
# 内核: 6.8.0-106-generic
# CPU:  Intel Xeon Platinum 8259CL @ 2.50GHz (24 核)
# 内存: 15964 MB
# CKB:  ckb 0.204.0 (e863939 2026-02-12) (仅限测试网)

# 1. 启动 CKB 测试网节点
cd /root && ./ckb run &

# 2. 运行稳定性测试
cd /root/ckb-probe
DURATION_HOURS=48 \
SAMPLE_SECS=10 \
  bash scripts/stability/stability-48h.sh

# 3. 生成报告
bash scripts/stability/generate-report.sh /path/to/stability-<timestamp>/

九、案例研究完整报告

Case 1: IBD 写入模式分析

9.1.1 测试概要

项目
执行时间 2026-04-22 16:05 ~ 16:27 UTC
持续时长 22 分钟 (1,329 秒)
起始 tip 20,851,949
结束 tip 20,852,146
同步区块数 197
平均同步速度 8.89 区块/分钟
采样点数 133 (每 10 秒采样)
退出原因 tip 停滞,节点已追上网络最新高度

9.1.2 各操作统计

操作 平均 QPS 平均延迟 (us) 平均 P50 (us) 平均 P99 (us) 平均吞吐 (B/s)
GET 109.7 201.9 8.2 7,057.2 9,118
PUT 4.3 5.0 4.5 24.2 509
WRITE 0.0 47.8 41.2 99.0 -
ITER_NEW 8.0 23.1 19.5 60.1 -
TXN_COMMIT 0.1 157.4 150.8 343.0 509

9.1.3 写入模式演变(前半段 vs 后半段)

操作 阶段 平均 QPS 平均延迟 (us) 平均 P99 (us) 平均吞吐 (B/s)
GET 前半段 121.2 214.7 7,506.8 10,212
GET 后半段 98.4 189.4 6,614.2 8,041
PUT 前半段 5.0 5.4 27.2 573
PUT 后半段 3.6 4.5 21.3 447
WRITE 前半段 0.0 52.3 153.4 -
WRITE 后半段 0.0 43.4 45.5 -
ITER_NEW 前半段 16.0 23.8 64.0 -
ITER_NEW 后半段 0.1 22.5 56.1 -
TXN_COMMIT 前半段 0.1 159.6 363.4 573
TXN_COMMIT 后半段 0.0 155.3 322.8 447

分析:

  • 前半段处于活跃 IBD 阶段,GET QPS 较高 (121.2),ITER_NEW 活跃 (16.0 QPS),反映大量区块验证和状态查询
  • 后半段节点逐渐追上 tip,各项 QPS 均有所下降,ITER_NEW 降至 0.1(接近 steady state)
  • WRITE P99 从前半段 153.4us 降至后半段 45.5us,写放大效应随 IBD 接近尾声而减弱
  • PUT 延迟始终很低(4~5us),说明单次写入操作非常轻量

9.1.4 同步速度演变

时间窗口 新增区块 速度 (区块/分钟)
0 ~ 5 分钟 66 13.2
5 ~ 10 分钟 42 8.4
10 ~ 15 分钟 34 6.8
15 ~ 20 分钟 28 5.6
20 ~ 25 分钟 9 1.8

同步速度持续下降,从 13.2 区块/分钟降至 1.8,最终 tip 停滞。节点数据已接近网络最新高度,符合 “追赶 → 稳态” 的预期曲线。

9.1.5 异常事件

测试期间检测到 6 个异常事件,全部为 ITER_NEW 操作:

  [16:20:45] ITER_NEW: avg=90.1us (基线=25.66us, 1.80x) p99=1572.86us 触发=P99
  [16:20:55] ITER_NEW: avg=77.36us (基线=25.66us, 1.55x) p99=1572.86us 触发=P99
  [16:21:05] ITER_NEW: avg=77.0us (基线=25.66us, 1.54x) p99=1572.86us 触发=P99
  [16:21:15] ITER_NEW: avg=90.29us (基线=25.66us, 1.81x) p99=1572.86us 触发=P99
  [16:21:25] ITER_NEW: avg=67.88us (基线=25.66us, 1.36x) p99=1572.86us 触发=P99
  [16:21:35] ITER_NEW: avg=68.4us (基线=25.66us, 1.37x) p99=1572.86us 触发=P99

异常集中在 16:20~16:21 的 1 分钟内,与 RocksDB 后台 compaction 争用 I/O 带宽一致,属于正常瞬态波动。

9.1.6 Case 1 结论

  • ckb-probe 在 IBD 阶段成功捕获了完整的 RocksDB 操作模式
  • GET 是主导操作(平均 109.7 QPS),驱动区块验证和状态读取
  • 写入负载较轻(PUT 4.3 QPS),写放大不显著
  • 节点在 22 分钟内从 IBD 追赶至网络最新高度,同步速度符合预期
  • 探针零崩溃、零事件丢失,对节点同步无可观测影响

Case 2: 压缩风暴捕获

9.2.1 测试概要

项目
执行时间 2026-04-24 05:30 ~ 06:00 UTC
持续时长 30 分钟 (1,800 秒)
调优方式 替换 default.db-options 为 aggressive 参数
采样帧数 362
慢操作总数 6,112 (阈值 > 1,000us)
BPF 事件丢失 0 / 6,112 (0.0000%)

9.2.2 应用的 aggressive 调优参数

参数 默认值 目的
level0_file_num_compaction_trigger 1 4 每产生 1 个 L0 文件就触发压缩
level0_slowdown_writes_trigger 2 20 2 个 L0 文件时减速写入
level0_stop_writes_trigger 3 36 3 个 L0 文件时停止写入
max_background_jobs 1 6 限制后台线程,制造压缩瓶颈
target_file_size_base 1 MB 64 MB 小文件 → 更多文件 → 更频繁压缩
max_bytes_for_level_base 10 MB 256 MB 降低层级容量阈值
write_buffer_size 4 MB 8 MB 频繁 flush → 更多 L0 文件

9.2.3 慢操作统计

在 aggressive 调优下,30 分钟内共捕获 6,112 个超过 1,000us 的慢操作:

操作 显示样本数 平均延迟 (us) 最大延迟 (us)
GET 2,880 6,988 20,242
TXN_COMMIT 8 3,445 8,389

慢操作速率演变:

时间段 每 60 秒慢操作数
初始阶段 350 / 5s (等效 ~4,200/min)
中期 ~5,930 / 60s
后期 ~6,050 / 60s
最终 6,112 / 60s

慢操作数量随时间递增,从初始 ~4,200/min 增长至 ~6,100/min,反映 RocksDB 在 aggressive 参数下 L0 文件持续积压,压缩争用 I/O 带宽导致 GET 延迟大幅上升。GET 平均延迟 6,988us(约 7ms),比正常运行时的 ~200us 高出约 35 倍,最大延迟达 20,242us(约 20ms)。

9.2.4 慢操作样本

  GET    │   4,449μs │        —
  GET    │   8,490μs │        —
  GET    │   3,308μs │        —
  GET    │   7,620μs │        —
  GET    │   9,957μs │        —
  GET    │  10,378μs │        —
  GET    │   5,870μs │        —
  GET    │   8,240μs │        —
  GET    │   4,651μs │      8 B
  GET    │   8,333μs │     32 B
  GET    │   5,477μs │    240 B
  GET    │   2,635μs │    101 B
  GET    │   7,087μs │      8 B
  GET    │   5,890μs │    240 B
  GET    │   6,499μs │    101 B
  GET    │   9,372μs │      8 B

9.2.5 执行过程

[05:30:19] 备份 default.db-options -> /data/default.db-options.backup-case2
[05:30:19] 替换 db-options 为 aggressive RocksDB 调优
[05:30:19] 停止当前 CKB
[05:30:21] 用 aggressive 调优重启 CKB
[05:30:23] CKB 运行中, PID=2105913
[05:30:27] ckb-probe 挂载, PID=2106838 (--slow --threshold 1000 --interval 5)
[05:30:27] 等待 ANOMALY DETECTED (最多 1800 秒)...
[06:00:28] 超时 (slow 模式不产生 ANOMALY DETECTED 标记)
[06:00:31] 恢复原始 db-options
[06:00:31] 完成

9.2.6 Case 2 结论

  • aggressive 调优成功制造了压缩风暴:GET 延迟从正常 ~200us 飙升至平均 6,988us (35x)
  • ckb-probe 在 30 分钟内成功捕获 6,112 个慢操作,零事件丢失
  • 慢操作几乎全部为 GET (99.7%),因为压缩占用磁盘 I/O 导致读放大
  • 脚本未检测到 ANOMALY DETECTED 标记,这是因为 --slow 模式不产生该标记(该标记仅在 --json 模式下输出)。数据本身是完整有效的
  • db-options 已在测试结束后自动恢复

十、后续计划

Week 7:优化加固与结项准备

  1. JSON 全局输出 — 确保所有模式的 JSON 输出格式统一、字段完整
  2. 制作完整演示说明文档 — 结构化的文字演示报告(Markdown),覆盖五个演示流程步骤,附完整终端输出和说明

Week 8:发布与结项

  1. 中英双语文档定稿 — 各类文档最终审校
  2. GitHub v0.1.0 Release — 打 tag、写 release notes、附带预编译 binary
  3. 结项报告 — 按 main_proj.md 规范整理全部交付物、验收清单、已知限制
  4. 社区分享 — 最终月度报告提交
4 Likes