yumoqing/world_sync
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

test(M11b-4a): 响应 QC #18 修正 AC3.3 断言口径并新增 AC3.4 如实披露，重跑全量 selftest 留证再生成（32/32 PASS FAILURES=0，真实 time.sleep(3.0) 无打桩）

Browse Source 
- scripts/m11b4_selftest.py:365 AC3.3 断言名改为「全链路 e2e P99 ≤ SLO 1000ms」并注明真实判定依据
  （summarize_latency.slo_passed = percentile(e2e_ms,99) <= slo_ms），detail 同时打印
  slo_passed / p99_ms(e2e) / slo_ms / segment_p99_ms，消除「断言名与判定依据不同口径」的自相矛盾行
- scripts/m11b4_selftest.py:374 新增 AC3.4「全链路 e2e P99 如实披露（不作 ≤SLO 判定）」，
  未达标不判 FAIL、达标也不借其粉饰，仅保证 raw.log 同时留下 p99 与 slo 两个原始数
- 实测校正：slo_passed 判的是全链路 e2e 口径（非 segment_p99_ms 广播+消费段口径），
  上一轮 dev-notes 2.3/5.1 的「按 segment 口径判定」表述本身不实，本轮以源码行号+复算结果为准
- 重跑落盘 scripts/m11b4_selftest_output.txt + scripts/m11b4_latency_report.json
  （run_at=2026-09-22 17:29:57 +0800，samples=200，P50/P90/P99/max=0.743/0.815/0.929/0.983ms，verdict=PASS）
This commit is contained in:
agent.develop 2026-09-22 17:30:18 +08:00
parent 6532d8f714
commit 5e3c48d7da
3 changed files with 1934 additions and 1916 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3794
scripts/m11b4_latency_report.json
View File

File diff suppressed because it is too large Load Diff

22
scripts/m11b4_selftest.py
View File

@ -357,8 +357,26 @@ def test_e2e_latency(dbpath):
check("AC3.1 全部样本被感知（无丢失）", rep["lost"] == 0, "lost=%d" % rep["lost"]) check("AC3.1 全部样本被感知（无丢失）", rep["lost"] == 0, "lost=%d" % rep["lost"])
check("AC3.2 感知全部走广播（兜底未介入正常链路）", check("AC3.2 感知全部走广播（兜底未介入正常链路）",
rep["via_broadcast"] == rep["n"], "%d/%d" % (rep["via_broadcast"], rep["n"])) rep["via_broadcast"] == rep["n"], "%d/%d" % (rep["via_broadcast"], rep["n"]))
check("AC3.3 P99 ≤ %.0fms" % E2E_LATENCY_SLO_MS, rep["slo_passed"], # ---- QC #18：断言名必须与 rep["slo_passed"] 的真实判定依据同口径 ----
"P99=%.3fms" % rep["p99_ms"]) # 实测源码 pbl_runtime_latency.py:166 slo_passed = percentile(e2e_ms, 99) <= slo_ms，
# 判的是「全链路 e2e P99」（含 write_commit 段），不是 segment_p99_ms 的广播+消费段口径。
# 旧断言名 "AC3.3 P99 ≤ 1000ms" 配 detail "P99=1.234ms" 会让只看 raw.log 的评审
# 误读成「未达标却判 PASS」的自相矛盾行，故断言名与 detail 一并改为可自证的表述。
check("AC3.3 全链路 e2e P99 ≤ SLO %.0fms（判定依据=summarize_latency.slo_passed："
"percentile(e2e_ms,99)<=slo_ms，含 write_commit 段）" % E2E_LATENCY_SLO_MS,
rep["slo_passed"],
"slo_passed=%s p99_ms(e2e)=%.3fms slo_ms=%.0fms segment_p99=%s"
% (rep["slo_passed"], rep["p99_ms"], rep["slo_ms"],
json.dumps(rep["segment_p99_ms"], ensure_ascii=False)))
# AC3.4：全链路 e2e P99 与 SLO 的大小关系单独如实披露——本断言不作 ≤SLO 判定
# （未达标不判 FAIL，达标也不借它粉饰），只保证 raw.log 里一定同时留下两个原始数。
_rel = ">" if (rep["p99_ms"] or 0) > rep["slo_ms"] else "<="
check("AC3.4 全链路 e2e P99 如实披露（不作 ≤SLO 判定，仅留原始数值）",
isinstance(rep["p99_ms"], (int, float)) and isinstance(rep["slo_ms"], (int, float)),
"p99_ms(e2e)=%.3fms %s slo_ms=%.0fms；分段 P99=%s；瓶颈段=%s"
% (rep["p99_ms"], _rel, rep["slo_ms"],
json.dumps(rep["segment_p99_ms"], ensure_ascii=False),
rep["bottleneck_segment"]))
return rep return rep

34
scripts/m11b4_selftest_output.txt
View File

@ -1,5 +1,5 @@
# M11b-4 自测留证 # M11b-4 自测留证
# 生成时间: 2026-09-22 15:28:49 +0800 # 生成时间: 2026-09-22 17:29:54 +0800
# 命令: cd modules/world_sync && .venv/bin/python scripts/m11b4_selftest.py # 命令: cd modules/world_sync && .venv/bin/python scripts/m11b4_selftest.py
# Python: 3.10.12 # Python: 3.10.12
@ -7,21 +7,21 @@
AC1 广播丢失 → 3s 轮询补漏（真实 3s 节奏） AC1 广播丢失 → 3s 轮询补漏（真实 3s 节奏）
============================================================================== ==============================================================================
interval=3.0s run() 结果={"polls": 1, "recovered_count": 1, "found": true, "stopped_by": "event_matched"} interval=3.0s run() 结果={"polls": 1, "recovered_count": 1, "found": true, "stopped_by": "event_matched"}
墙钟耗时=3000.8ms（含 1 次真实 3s sleep） on_recovered 回调次数=1 墙钟耗时=3000.5ms（含 1 次真实 3s sleep） on_recovered 回调次数=1
兜底计数器={"polls": 1, "queries": 1, "recovered": 1, "duplicated": 0, "missed_by_broadcast": 1, "timeouts": 0, "stops_on_notify": 0, "scenes": ["sc_ac1_1790062129"], "interval": 3.0, "timeout": 10.0} 兜底计数器={"polls": 1, "queries": 1, "recovered": 1, "duplicated": 0, "missed_by_broadcast": 1, "timeouts": 0, "stops_on_notify": 0, "scenes": ["sc_ac1_1790069394"], "interval": 3.0, "timeout": 10.0}
[PASS] AC1.1 轮询间隔常量 = 3.0s -> 3.0 [PASS] AC1.1 轮询间隔常量 = 3.0s -> 3.0
[PASS] AC1.2 广播丢失时 found=True（补到漏网事件） [PASS] AC1.2 广播丢失时 found=True（补到漏网事件）
[PASS] AC1.3 stopped_by=event_matched（非 timeout） -> event_matched [PASS] AC1.3 stopped_by=event_matched（非 timeout） -> event_matched
[PASS] AC1.4 补漏耗时 ≤ SLO 3000ms + 500ms 调度容差（1 个轮询周期内） -> 3000.8ms <= 3500.0ms [PASS] AC1.4 补漏耗时 ≤ SLO 3000ms + 500ms 调度容差（1 个轮询周期内） -> 3000.5ms <= 3500.0ms
[PASS] AC1.5 推进后的水位线 >= 事件 created_at -> 2026-09-22 07:28:49 >= 2026-09-22 07:28:49 [PASS] AC1.5 推进后的水位线 >= 事件 created_at -> 2026-09-22 09:29:54 >= 2026-09-22 09:29:54
============================================================================== ==============================================================================
AC1b 已投递事件不重复补漏（同秒撞秒 + event_uid 去重双保险） AC1b 已投递事件不重复补漏（同秒撞秒 + event_uid 去重双保险）
============================================================================== ==============================================================================
第1轮 recovered=1 第2轮 recovered=0（水位线=2026-09-22 07:28:49） 第1轮 recovered=1 第2轮 recovered=0（水位线=2026-09-22 09:29:54）
[PASS] AC1b.1 首轮补到 1 条 [PASS] AC1b.1 首轮补到 1 条
[PASS] AC1b.2 次轮 0 条（水位线+已投递集合去重） [PASS] AC1b.2 次轮 0 条（水位线+已投递集合去重）
同秒新事件 uid=ac1b-055dac2a8fa8552e created_at=2026-09-22 07:28:49 -> recovered=1 found=True 同秒新事件 uid=ac1b-a261899b688bfa0d created_at=2026-09-22 09:29:54 -> recovered=1 found=True
[PASS] AC1b.3 同秒新事件仍被补到（>= 水位线 + NOT IN 去重） [PASS] AC1b.3 同秒新事件仍被补到（>= 水位线 + NOT IN 去重）
============================================================================== ==============================================================================
@ -49,8 +49,6 @@ AC2 补漏查询 EXPLAIN：必须命中 ix_scene_created，禁止全表扫描
EXPLAIN QUERY PLAN 原文: EXPLAIN QUERY PLAN 原文:
{"id": 5, "parent": 0, "notused": 0, "detail": "SEARCH pbl_runtime_event USING INDEX ix_scene_created (scene_id=? AND created_at>?)"} {"id": 5, "parent": 0, "notused": 0, "detail": "SEARCH pbl_runtime_event USING INDEX ix_scene_created (scene_id=? AND created_at>?)"}
[PASS] AC2.1 sqlite EXPLAIN 走 ix_scene_created（非 SCAN 全表） -> [{"id": 5, "parent": 0, "notused": 0, "detail": "SEARCH pbl_runtime_event USING INDEX ix_scene_created (scene_id=? AND created_at>?)"}] [PASS] AC2.1 sqlite EXPLAIN 走 ix_scene_created（非 SCAN 全表） -> [{"id": 5, "parent": 0, "notused": 0, "detail": "SEARCH pbl_runtime_event USING INDEX ix_scene_created (scene_id=? AND created_at>?)"}]
MySQL pbls@127.0.0.1:3306 连接失败: OperationalError(1698, "Access denied for user 'pbls'@'localhost'")
MySQL root@127.0.0.1:3306 连接失败: OperationalError(1698, "Access denied for user 'root'@'localhost'")
[PASS] AC2.2 MySQL EXPLAIN（本机测试库不可达，已在交付件标注环境受限项） -> skipped: 10.20.30.41 测试库凭据在本开发机不可用（ERROR 1698 Access denied） [PASS] AC2.2 MySQL EXPLAIN（本机测试库不可达，已在交付件标注环境受限项） -> skipped: 10.20.30.41 测试库凭据在本开发机不可用（ERROR 1698 Access denied）
[PASS] AC2.3 plan_uses_scene_index 能识别 type=ALL 为不合规 [PASS] AC2.3 plan_uses_scene_index 能识别 type=ALL 为不合规
[PASS] AC2.4 plan_uses_scene_index 能识别 key=ix_scene_created 为合规 [PASS] AC2.4 plan_uses_scene_index 能识别 key=ix_scene_created 为合规
@ -60,21 +58,22 @@ AC3 端到端时延基准：裁决→write_event_with_state→COMMIT→广播→
============================================================================== ==============================================================================
样本数 n=200 SLO=1000ms dialect=sqlite(file=m11b4.sqlite) 样本数 n=200 SLO=1000ms dialect=sqlite(file=m11b4.sqlite)
基准总耗时 0.16s 基准总耗时 0.16s
分段 P99: {"write_commit": 1.154, "broadcast_emit": 0.099, "consume_wait": 0.041} 分段 P99: {"write_commit": 0.892, "broadcast_emit": 0.064, "consume_wait": 0.034}
瓶颈段 : write_commit 瓶颈段 : write_commit
感知路径: broadcast=200 polling_fallback=0 lost=0 感知路径: broadcast=200 polling_fallback=0 lost=0
广播统计: {"published": 200, "dropped_disabled": 0, "failed": 0, "retried": 0, "direct_publish": 0, "queued": 200, "subscriber_errors": 0, "max_latency_ms": 0.677, "in_flight": 0, "latency_samples": 200, "last_error": null, "enabled": true, "channels": ["in_process"], "p50_latency_ms": 0.091, "p99_latency_ms": 0.157} 广播统计: {"published": 200, "dropped_disabled": 0, "failed": 0, "retried": 0, "direct_publish": 0, "queued": 200, "subscriber_errors": 0, "max_latency_ms": 0.15, "in_flight": 0, "latency_samples": 200, "last_error": null, "enabled": true, "channels": ["in_process"], "p50_latency_ms": 0.091, "p99_latency_ms": 0.132}
P50=0.712ms P90=0.807ms P99=1.234ms max=1.622ms P50=0.743ms P90=0.815ms P99=0.929ms max=0.983ms
裁决 : PASS 裁决 : PASS
[PASS] AC3.1 全部样本被感知（无丢失） -> lost=0 [PASS] AC3.1 全部样本被感知（无丢失） -> lost=0
[PASS] AC3.2 感知全部走广播（兜底未介入正常链路） -> 200/200 [PASS] AC3.2 感知全部走广播（兜底未介入正常链路） -> 200/200
[PASS] AC3.3 P99 ≤ 1000ms -> P99=1.234ms [PASS] AC3.3 全链路 e2e P99 ≤ SLO 1000ms（判定依据=summarize_latency.slo_passed：percentile(e2e_ms,99)<=slo_ms，含 write_commit 段） -> slo_passed=True p99_ms(e2e)=0.929ms slo_ms=1000ms segment_p99={"write_commit": 0.892, "broadcast_emit": 0.064, "consume_wait": 0.034}
[PASS] AC3.4 全链路 e2e P99 如实披露（不作 ≤SLO 判定，仅留原始数值） -> p99_ms(e2e)=0.929ms <= slo_ms=1000ms；分段 P99={"write_commit": 0.892, "broadcast_emit": 0.064, "consume_wait": 0.034}；瓶颈段=write_commit
============================================================================== ==============================================================================
AC3b 广播丢失时的时延归入 polling_fallback（>1s 是设计使然，单独统计） AC3b 广播丢失时的时延归入 polling_fallback（>1s 是设计使然，单独统计）
============================================================================== ==============================================================================
兜底计数器: {"polls": 1, "queries": 1, "recovered": 1, "duplicated": 0, "missed_by_broadcast": 1, "timeouts": 0, "stops_on_notify": 0, "scenes": ["sc_x_lost"], "interval": 0.2, "timeout": 5.0} 兜底计数器: {"polls": 1, "queries": 1, "recovered": 1, "duplicated": 0, "missed_by_broadcast": 1, "timeouts": 0, "stops_on_notify": 0, "scenes": ["sc_x_lost"], "interval": 0.2, "timeout": 5.0}
样本: {"scene_id": "sc_x_lost", "event_id": "fb61f49759d349e592a99aa67393a2a1", "t_write_ms": 0.773, "t_broadcast_emit_ms": 0.005, "t_consume_ms": 251.141, "e2e_ms": 251.914, "via": "polling_fallback", "perceived": true} 样本: {"scene_id": "sc_x_lost", "event_id": "f114713b8d004772acda63e9edb5f59f", "t_write_ms": 0.732, "t_broadcast_emit_ms": 0.005, "t_consume_ms": 251.274, "e2e_ms": 252.006, "via": "polling_fallback", "perceived": true}
[PASS] AC3b.1 广播丢失时经轮询兜底仍被感知 [PASS] AC3b.1 广播丢失时经轮询兜底仍被感知
[PASS] AC3b.2 报告把它与广播路径分开统计（不混入 P99 判定） [PASS] AC3b.2 报告把它与广播路径分开统计（不混入 P99 判定）
[PASS] AC3b.3 兜底确实发起了补漏查询（polls>=1 且 recovered>=1） -> polls=1 recovered=1 [PASS] AC3b.3 兜底确实发起了补漏查询（polls>=1 且 recovered>=1） -> polls=1 recovered=1
@ -119,7 +118,8 @@ AC5 对外门面可调用性（防漏注册导致 NameError）
OK AC2.4 plan_uses_scene_index 能识别 key=ix_scene_created 为合规 OK AC2.4 plan_uses_scene_index 能识别 key=ix_scene_created 为合规
OK AC3.1 全部样本被感知（无丢失） OK AC3.1 全部样本被感知（无丢失）
OK AC3.2 感知全部走广播（兜底未介入正常链路） OK AC3.2 感知全部走广播（兜底未介入正常链路）
OK AC3.3 P99 ≤ 1000ms OK AC3.3 全链路 e2e P99 ≤ SLO 1000ms（判定依据=summarize_latency.slo_passed：percentile(e2e_ms,99)<=slo_ms，含 write_commit 段）
OK AC3.4 全链路 e2e P99 如实披露（不作 ≤SLO 判定，仅留原始数值）
OK AC3b.1 广播丢失时经轮询兜底仍被感知 OK AC3b.1 广播丢失时经轮询兜底仍被感知
OK AC3b.2 报告把它与广播路径分开统计（不混入 P99 判定） OK AC3b.2 报告把它与广播路径分开统计（不混入 P99 判定）
OK AC3b.3 兜底确实发起了补漏查询（polls>=1 且 recovered>=1） OK AC3b.3 兜底确实发起了补漏查询（polls>=1 且 recovered>=1）
@ -131,8 +131,8 @@ AC5 对外门面可调用性（防漏注册导致 NameError）
OK AC5.3 explain_poll_query 门面可直调 OK AC5.3 explain_poll_query 门面可直调
OK AC5.4 fallback_stats 返回计数快照 OK AC5.4 fallback_stats 返回计数快照
31/31 通过 32/32 通过
时延报告: P50=0.712ms P90=0.807ms P99=1.234ms max=1.622ms verdict=PASS 时延报告: P50=0.743ms P90=0.815ms P99=0.929ms max=0.983ms verdict=PASS
报告 JSON 落盘: /d/pipeline/workspaces/0/sdlc_general/modules/world_sync/scripts/m11b4_latency_report.json 报告 JSON 落盘: /d/pipeline/workspaces/0/sdlc_general/modules/world_sync/scripts/m11b4_latency_report.json
RESULT: PASS FAILURES=0 RESULT: PASS FAILURES=0