外观
R8-Fix-8:Pmd3 Pump / ActivityTrace Filter Active-Time Fairness 方案
状态:implemented · gate-open / E2 completed / E4 pending
本方案是 R8-Fix-7 之后,针对 Build 69 真机 E4 实测数据的定向修复批次。 它不是 FPS / FrameTime 的重新设计:Display 指标公式、Source Owner、 FrameLifetime 白名单与解码器、
MetricRegistry、CapturePlan、CoreProfile 策略、 Pmd3 pump 公平性的 32 events 上界、ActivityTrace filter 公平性的 64 messages 上界、两者的 1ms 预算、R8-Fix-7 的 realtime consumer burst(8 events / 1.0ms)、Pmd3Subscription队列 2048、consumer drain 0.5s、Python 关闭预算 8s、 Swift Core watchdog 10s、Device Condition 20s 采样间隔全部保持不变。 本批次只做一件事——把两处 fairness 的"时间门槛"从"包含上游await的 wall-span" 改成"只计自身同步工作的 active-span",并把每次让出的原因记成可审计的直方图。证据等级声明:本批次的代码与自动化测试验证为 E2;方案设计目标是为 下一次真机 E4 提供可验证的行为,因此在真机 E4 执行前,本批次 不得记为
validated,也不得自建发布包。本批次不构建 Build 70。
1. 背景:Build 69 真机 E4 把残余延迟钉在订阅队列里
Build 69(纯 Display,Session 1bc4d6c4-9cf0-43e2-9351-f2ff0be3b630,时长 81.878s, 交付 768 条 FrameLifetime)完成了 R8-Fix-6 引入的七层 host 时间戳分层诊断。 逐层读出的事实如下:
| 层 | 指标 | 实测(P95) | 读数 |
|---|---|---|---|
| tap → filter 匹配 | filterMatched − tapCallback | — | 正常 |
| filter → pump 入队 | subscriptionEnqueue − filterMatched | 0.035ms | 干净 |
| pump 出队 → adapter | subscriptionDequeue − subscriptionEnqueue | 0.017ms | 干净 |
| adapter → realtime | adapterYield − subscriptionDequeue | 0.247ms | 干净 |
| realtime → ingress | ingressAccepted − adapterYield | 0.021ms | 干净 |
| 订阅队列等待 | pumpQueueWait | P50 157.596ms / P95 354.888ms / Max 563.371ms | 唯一的异常层 |
也就是说,除订阅队列以外,每一层都在亚毫秒量级上干净得毫无解释力; 768 条帧在 Pmd3Subscription 内部平均等了 157ms。
同一场 Session 的 pump / filter 公平性诊断给出了决定性指纹:
text
deliveredEventCount 768
pumpYieldCount 768 <- 每条交付事件恰好一次显式让出
pumpMaxBurstCount 1 <- 每次 burst 只处理 1 条就结束
pumpMaxActiveBurstDurationMs 0.058 <- pump 自己的同步工作只有 58 微秒
filterYieldCount 883
filterMaxBurstMessageCount 16 <- 远未触及 64 的上界
filterMaxActiveBurstDurationMs 2.131pumpMaxBurstCount == 1 且 pumpYieldCount == deliveredEventCount 是同一个因果的两面: pump 每拿到一条事件就立刻显式让出一次,于是每条事件都要等一整个调度往返才被交付。 在 60Hz 源(上游 await ≈ 16.6ms)下,理论上队列里最多只该积压 1–2 条; 但实测 P50 157ms 意味着队列里积压了约 10 条,而且是稳定地积压—— 因为 pump 的处理速度被"每条一次显式让出"钉死在调度延迟上。
2. 根因:wall-span 时间门槛把上游等待二次计费
R8-Fix-5 引入的 pump 公平性门禁是:
python
burst_duration_ns = now_ns - burst_started_ns # 从 burst 开始算的墙钟跨度
if burst_count >= 32 or burst_duration_ns >= 1_000_000:
await asyncio.sleep(0) # 显式让出burst_started_ns 在 burst 开始时打点,跨越了上游 async for 的 await。 于是 60Hz 源上,pump 拿到第 1 条事件后进入下一轮循环时必然已经在 await 上等了 16.6ms:
- 上游
await本身已经挂起本任务、把事件循环交还给其他人——这是第一次让出; await返回后burst_duration_ns立刻 > 1ms,门禁再触发一次await asyncio.sleep(0)——这是对同一次等待的第二次让出。
pumpMaxActiveBurstDurationMs = 0.058ms 恰好证明 pump 自己的同步工作(队列满检查、丢弃、 入队、计数)只花 58 微秒——时间门槛是被上游等待撞响的,不是被 pump 的工作撞响的。 换句话说:这条时间门槛在"上游已经用 await 让过出"的场景里是冗余的, 而它付出的代价是每条事件额外一个调度往返。
filterMaxBurstMessageCount = 16 对应的是完全相同的缺陷。filter 的门禁是:
python
burst_duration_ns = last_ns - burst_started_ns # last_ns 每条匹配消息都刷新last_ns 在每条匹配的 FrameLifetime 上被刷新,于是 60Hz 下 burst_duration_ns每次都会超过 1ms —— 883 次 filter yield、每次 burst 只有 16 条消息(上界是 64), 而 filter 的真实同步工作上界只有 2.131ms(这 2.131ms 还是"匹配帧解码"这条真有活干的路径)。
结论写死在诊断语义上:wall-span 不是事件循环占用量的度量。 R8-Fix-6 已经把它降级为 legacy 诊断(pumpMaxBurstDurationMs / filterMaxBurstDurationMs) 并新增了只计同步工作的 *MaxActiveBurstDurationMs,但 R8-Fix-5 留下的门禁仍在比较 wall-span。
3. 修复设计
3.1 门禁语义:时间门槛只比 active-span
两处门禁都改为先判数量上界,再判 active 时间上界:
python
# Pmd3Subscription._pump()
if burst_count >= PUMP_FAIRNESS_MAX_BURST_EVENTS: # 32,未变
reason = PUMP_YIELD_EVENT_LIMIT # "event-limit"
elif burst_active_ns >= PUMP_FAIRNESS_MAX_BURST_NS: # 1ms,未变
reason = PUMP_YIELD_ACTIVE_TIME # "active-time"
else:
reason = Nonepython
# _ActivityTraceFilteredStream.__aiter__()
if burst_count >= ACTIVITYTRACE_FILTER_MAX_BURST_MESSAGES: # 64,未变
reason = ACTIVITYTRACE_FILTER_YIELD_MESSAGE_LIMIT # "message-limit"
elif burst_active_ns >= ACTIVITYTRACE_FILTER_MAX_BURST_NS: # 1ms,未变
reason = ACTIVITYTRACE_FILTER_YIELD_ACTIVE_TIME # "active-time"burst_active_ns 的口径沿用 R8-Fix-6 已落地的定义:在上游 await 前后打点, 把这段等待加回到 span 之外,只累计 await 返回之后 pump / filter 自己做的同步工作。 这与 R8-Fix-7 给 realtime consumer 定下的规范是同一个模式:
python
# RealtimeConsumerFairness(R8-Fix-7,本批次未改动)
if count >= MAX_BURST_EVENTS: reason = "event-limit"
elif active_ns >= MAX_ACTIVE_NS: reason = "active-time"3.2 让出原因直方图:让结论可审计
pumpYieldCount 单独一个数字无法区分"数量上界在履职"与"时间门槛被上游等待撞响"。 本批次为两处各加一个只有两个键的直方图,随 diagnostics() / snapshot() 输出:
text
pumpYieldReasonCounts = {"event-limit": N, "active-time": M}
filterYieldReasonCounts = {"message-limit": N, "active-time": M}设计上不存在 wall-time 这个键——因为 wall-span 已经不再是调度理由, 它只作为 legacy 诊断保留。下一次真机 E4 只要看直方图就能判定: 若 active-time 在纯 Display 会话里占绝对多数,说明残余让出都是"真的有活干"; 若出现"pumpYieldCount 等于交付条数"的形态,则说明有新缺陷把门禁又推回了 wall 语义。
3.3 legacy 诊断原样保留(历史连续性)
pumpMaxBurstDurationMs / filterMaxBurstDurationMs 不改名、不删除、口径不变(仍含上游等待)。 需要诚实记录一个副作用:既然门禁不再比较 wall-span,一个 burst 现在可以合法地 跨越多次上游等待(60Hz 源上 32 条事件的 burst 可以横跨约 0.5 秒墙钟), 因此 legacy 数字会随之变大。这是"指标按其定义工作",不是回归—— 判断事件循环占用要看 *MaxActiveBurstDurationMs 与 *YieldReasonCounts。 这一点已写进代码注释与本文档,避免后续被误读为"pump 占住事件循环更久了"。
3.4 明确不改的东西
- pump 上界 32 events、filter 上界 64 messages、两者预算 1ms;
- R8-Fix-7 的 realtime consumer 有界 burst(
REALTIME_CONSUMER_MAX_BURST_EVENTS = 8/REALTIME_CONSUMER_MAX_ACTIVE_NS = 1_000_000)与其原因直方图; Pmd3Subscription队列 2048、consumer drain 0.5s、Python 关闭预算 8s、 Swift watchdog 10s、Device Condition 20s;- FPS / FrameTime / P95 / Jitter / Refresh Rate 公式、Source Owner、
RawEventEnvelope.SCHEMA、七层时间戳诊断本身。
4. 实现范围
| 文件 | 改动 |
|---|---|
MacApp/Sidecar/perfowl_collector_core/pmd3_backend.py | 新增 PUMP_YIELD_EVENT_LIMIT / PUMP_YIELD_ACTIVE_TIME 常量与 pump_yield_reason_counts;_pump() 门禁改判 burst_active_ns;新增 _close_pump_burst(reason) 统一记账;diagnostics() 输出 pumpYieldReasonCounts |
MacApp/Sidecar/perfowl_collector_core/display_performance.py | 新增 ACTIVITYTRACE_FILTER_YIELD_MESSAGE_LIMIT / _ACTIVE_TIME 常量与 filter_yield_reason_counts;ActivityTraceAcquisitionCensus.observe_filter_yield(reason) 取代裸 filter_yield_count += 1;snapshot() 输出 filterYieldReasonCounts;_ActivityTraceFilteredStream.__aiter__ 门禁改判 burst_active_ns;_subscription_snapshot() 透传 pumpYieldReasonCounts |
MacApp/Sidecar/tests/test_pump_filter_active_fairness.py | 新增:A–H 八组行为测试 + 两组 benchmark,内含冻结的 legacy 行为模拟器 |
MacApp/Sidecar/tests/test_pmd3_subscription_fairness.py | T2 拆为正/反两条(上游 wall 时间不得触发让出 / 真同步工作仍必须触发);T4、T6 增加原因直方图断言 |
MacApp/Sidecar/tests/test_display_pipeline_timing.py | a1、b1 两条 active-duration 测试补充"原因合法且无 wall-time 键"的断言 |
realtime.py 未改动:R8-Fix-7 的 consumer burst 逻辑不需要重新接线, pump 的直方图通过 Pmd3Subscription.diagnostics() 与 _subscription_snapshot() 两条既有路径暴露。
4.1 冻结的 legacy 行为模拟器(测试专用)
为了在同一条工作负载上直接测量 wall 语义与 active 语义的差别,新增测试模块内实现了 LegacyWallGatePump 与 LegacyWallGateFilteredStream——把 R8-Fix-8 之前的两处门禁逐字冻结在测试里。 它们只存在于测试,不进产品代码,作用是给"删掉的行为"留下可复现的对照臂(fail 时能打印差异, 而不是只能靠回忆)。这与 R8-Fix-7 E2 门禁修复里对 legacy comparator 的处理方式一致。
5. 实测数据(E2,隔离 worktree,基线 15e5a61)
5.1 决定性证据:Build 69 指纹被消除
真实节拍 120Hz × 1200 帧(不做时钟压缩,约 13s):
text
shipping(active-time) delivered=1200 yields=320/292 reasons={'event-limit': 0, 'active-time': 320/292} maxBurst=12/13 maxActive=1.614/1.746ms
legacy (wall-time) yields=1200 == delivered <- Build 69 的 768/768 指纹原样复现legacy 臂逐字复现了 Build 69 的形态(让出次数 == 交付条数), shipping 臂把它降到 292–320(降幅 73–76%),且全部由 active-time 解释。 这正是本次修复要证明的命题:wall 语义下"每条一次显式让出"是必然,不是负载特性。
5.2 上游等待不再入账
text
50ms 等待/事件 × 6 条 legacy wall span=210.957/308.616ms active=0.517/1.005ms yields=0~1wall-span 仍然忠实地携带上游等待(legacy 诊断保真),而 active-span 只有 0.5–1.0ms: 相差两个数量级。100 条 @10ms 的形态同理: legacy 100 次让出(每条一次)vs shipping 8–28 次(全部 active-time)。
5.3 时间门槛仍然可达(不是被削掉)
只把上游等待排除掉是不够的——门槛必须还能被真实的同步工作撞响,否则等于删掉了时间保护:
text
每事件注入 ~0.45ms 同步工作 × 9 条 -> yields=3 reasons={'event-limit': 0, 'active-time': 3} maxBurst=3 maxActive=1.407ms3 条 × 0.45ms ≈ 1.35ms 越过 1ms,门禁按 active-time 触发(数量上界 32 完全没参与), maxBurst=3 与"1ms ÷ 0.45ms"的算术前一致。时间门槛的语义被修正而非被削弱。
5.4 数量上界与抗饥饿底线保持(Build 66 不回归)
text
200000 同步 backlog delivered=200000 committed=200000 drops=0 yields=6250 reasons={'event-limit': 6250} maxBurst=32 maxGap=2.7~4.6ms
200000 拒绝洪水 messages=200000 yields=3125 reasons={'message-limit': 3125} maxBurst=64 maxGap=0.7~1.3ms
同步阻塞源 ×100 yields=3 reasons={'event-limit': 3} maxBurst=32 maxGap=16.6ms同步源(wall == active)下门禁只能由数量上界触发——这正是 Build 66 反饥饿地板: 32/64 的上界、maxBurst 精确等于上界、事件循环在每个 burst 后都被交还(maxGap 毫秒级)。 两处 1ms 的 active-time 在同步场景下 0 次触发,说明门禁没有出现"数量上界被时间上界顶掉"的偏移。
5.5 Filter 侧同构结论(含混合流)
Filter 的难点是 last_ns 每条匹配消息都刷新,所以用"帧 + 每帧噪声"的混合流 (57 帧 + 342 条噪声,共 399 条 @6ms)才能稳定测出 legacy 的每匹配一次让出:
text
shipping yields=9~13 reasons={'active-time': 7~13, 'message-limit': 0~2} maxBurst=31~64 wall=271~494ms active=1.025~1.056ms
legacy yields=57 == 匹配条数 reasons={'wall-time-legacy': 57}
改善倍数 4.38x ~ 6.33x5.6 压缩 120Hz 基准:无吞吐退化
120Hz × 7200 帧 + 6 条噪声/帧,经真实 filter → pump → consumer 桥:
text
shipping/active-time matched=7200 consumed=7200 drops=0 pumpYields=225 {'event-limit': 225} filterYields=787 {'message-limit': 787}
queueWait p50=1.704 p95=3.077 p99=3.380 max=4.259ms heartbeat p95=0.69 max=1.35ms
elapsed=500.1ms throughput=14398 ev/s cpu=486ms rssDelta=0.0MB
legacy/wall-time matched=7200 consumed=7200 drops=0 pumpYields=401 {'wall-time-legacy': 401} filterYields=796 {'wall-time-legacy': 796}
queueWait p50=1.815 p95=3.228 p99=3.626 max=4.757ms heartbeat p95=0.83 max=1.17ms
elapsed=635.4ms throughput=11331 ev/s cpu=617ms rssDelta=0.0MBpumpQueueWait P95 3.077ms vs 3.228ms、Max 4.259ms vs 4.757ms、 吞吐 14398 vs 11331 ev/s(+27.1%)、CPU 486ms vs 617ms、rssDelta=0.0MB (无线性增长)。压缩基准里队列足够大所以两臂都不丢样,这恰好让吞吐对比只反映调度策略差异。
5.7 §49 重复稳定性(33 次独立进程)
text
pump idle ×10 10/10 PASS yields 8~28(全部 active-time,event-limit 恒 0) maxBurst 5~12 maxActive 1.078~1.446ms legacy 恒 100
filter idle ×10 10/10 PASS yields 9~13 maxBurst 31~64 active 1.025~1.056ms legacy 恒 57 改善 4.38~6.33x
120Hz shipping ×5 5/5 PASS
200000 pump backlog ×3 3/3 PASS 6250 event-limit maxBurst 32 maxGap 2.7~4.6ms elapsed 3069~3082ms
200000 flood ×3 3/3 PASS 3125 message-limit maxBurst 64 maxGap 0.7~1.3ms elapsed 925~1063ms
real-cadence 120Hz ×2 2/2 PASS yields 320/292(全部 active-time) legacy 恒 1200
==== overall: ALL PASS ====诚实标注:pump idle 形态下让出次数在 8~28/100 之间摆动(filter idle 为 9~13)。 这不是策略抖动,而是宿主属性——每次 await 恢复之后 pump 自身那一小段同步工作 (put_nowait、计数、时间戳)的实际开销取决于当时的调度与缓存状态, 在 10ms 节拍下攒够 1ms 需要 5~28 条事件。策略保证的是"上游等待无法再满足门槛" (这正是 legacy 恒为 100 的原因),而不是让出次数落在一个固定数字上。 因此测试断言写的是上界与"原因合法"(active-time 主导、event-limit 恒 0、 yields << delivered、legacy.yields == delivered),而不是精确值。 同理,filter idle 的 message-limit 偶发出现 1~2 次(一个 host 停顿恰好落在 64 条之内), 测试以 1% 预算而非 == 0 收紧,仍能在策略回退成时间驱动时失败。
6. 门禁与静态审计
text
专项新增模块 tests.test_pump_filter_active_fairness Ran 10 tests OK (41.266s)
专项 §49 重复 33 次独立进程 ALL PASS
Python 全量 Ran 705+ tests OK (0 failures / 0 errors)
Swift 全量 182 tests / 3 skipped / 0 failures
站点 知识门禁 + VitePress build PASS(0 报错 / 0 死链)
git diff --check 干净7. 保留的不变式
MacApp/Sidecar/** 之外无任何改动;逐条核对以下全部保持原值:
- pump 公平性上界
PUMP_FAIRNESS_MAX_BURST_EVENTS = 32、预算PUMP_FAIRNESS_MAX_BURST_NS = 1_000_000; - filter 公平性上界
ACTIVITYTRACE_FILTER_MAX_BURST_MESSAGES = 64、预算ACTIVITYTRACE_FILTER_MAX_BURST_NS = 1_000_000; - realtime consumer
REALTIME_CONSUMER_MAX_BURST_EVENTS = 8/REALTIME_CONSUMER_MAX_ACTIVE_NS = 1_000_000(未改动); Pmd3Subscription队列容量 2048(同步 backlog 测试里的 4096 只出现在 fixture);SOURCE_CONSUMER_DRAIN_TIMEOUT_SECONDS = 0.5;COLLECTOR_CLOSEOUT_SOFT_BUDGET_SECONDS = 8.0;DEVICE_CONDITION_INTERVAL_SECONDS = 20.0;- Swift
gracefulTimeout = runtimeKind == .core ? 10 : 2; - FPS / FrameTime / P95 / Jitter / Refresh Rate 公式、Source Owner、
RawEventEnvelope.SCHEMA(仍为perfowl.raw-event/1)、七层 host 时间戳诊断。
新增的两个直方图只有两个键,且不存在 wall-time:这是"wall-span 不再是调度理由" 这条设计决定在产物里的可审计证据,也是下一次真机 E4 的判据入口。
8. 边界与停止点
- 本批次不构建 Build 70、不执行真机 E4、不声明
validated; - 下一次真机 E4 的判据(沿用 R8-Fix-7 门禁并新增本批次两条):
pumpYieldReasonCounts/filterYieldReasonCounts不含wall-time键;- 纯 Display 会话的
pumpYieldCount显著小于deliveredEventCount(不得再出现 Build 69 的 768/768 形态); pumpQueueWaitP95 明显低于 354.888ms、且>500ms计数为 0;dataCompleteness=complete、ingressUndrained=0、848→ 交付 ≈ 消费;- Stop →
stopped< 2s、overallCloseoutStatus=clean、无graceful_stop_timeout; realtimeConsumerFairness.maxObservedBurstCount ≤ 8。
- 门禁保持 OPEN,等待下一次真机 E4;本批次只交付 E2。