R8-Fix-6:ActivityTrace 残余 Host 交付间隙分层诊断与 Closeout 任务分类修复方案
> 状态:implemented · gate-open / E2 completed / E4 pending > > 本方案是 R8-Fix-5.2 之后, > 针对 Build 67 真机 E4 实测数据的定向修复批次。 > 它不是 FPS / FrameTime 的重新设计:Display 指标公式、Source Owner、 > FrameLifetime 白名单与解码器、MetricRegistry、CapturePlan、CoreProfile 策略 > 全部保持不变。本批次只做两件事——把不知道在哪一层的 Host 交付间隙变成可归因的 > 证据,以及修正把辅助 sleeper 误判为 consumer drain 的分类缺陷。 > > 证据等级声明:本批次的代码与自动化测试验证为 E2;方案设计目标是为 > Build 68 真机 E4 提供可归因的证据,因此在真机 E4 执行前,本批次 > 不得记为 validated,也不得自建发布包。
1. 背景:Build 67 真机 E4 的两个事实
Build 67 真机 E4 同时给出了一个好消息和一个新问题,两者必须分开处理。
好消息(R8-Fix-4/5/5.1/5.2 的成果已生效):
- ActivityTrace FrameLifetime 交付 440 条、0 丢弃;
- FPS 样本 51/53 有效、FrameTime 50/53 有效(不再是 Build 66 的空白);
dataCompleteness=complete、ingressUndrained=0;- 关闭路径不再撞 Swift 10s watchdog。
新问题(本批次要解决的两个 P0):
1.1 问题 A:残余 Host 交付间隙,位置未知
真机捕获到一次 2878ms 的 hostReceive 间隙。同一次间隙里还包含一段 约 599ms 的真实源端呈现不连续(sourcePresentationDeltaMs,属设备侧真实掉帧, 不是 Perfowl 缺陷)。
问题不在于"有没有间隙",而在于间隙在哪一层。当前 Session 里唯一可用的时间戳是 adapter 最终观察到的那一个,它无法区分七层交付路径中的任何一层:
Layer 0 DTX / pymobiledevice3 传输(上游,host 无法进一步插桩)
Layer 1 ActivityTrace raw tap iterator
Layer 2 host 白名单过滤器(_ActivityTraceFilteredStream)
Layer 3 Pmd3Subscription pump(生产者)
Layer 4 subscription 有界队列
Layer 4' Pmd3Subscription.__anext__(消费者侧)
Layer 5 RawAdapter → realtime consume(消费者)
Layer 6 OrderedRawIngress 入队
没有分层时间戳,"2878ms 的间隙"就只能被猜测,而猜测在这一层是不可接受的: 把上游 DTX 传输的停顿记成 Perfowl 的消费者停顿,会导致下一轮去"修"一个不存在的 bug。
1.2 误导性诊断:pumpMaxBurstDurationMs 是 wall-span,不是 event-loop 占用
Build 67 的 pumpMaxBurstDurationMs 读数约 2578ms,一度被读作 "pump 占住了事件循环 2.5 秒"。这是口径误读:
# 旧口径(legacy wall-span)
burst_started_ns = time.monotonic_ns()
async for item in self._source: # <- await 上游,等待时间被算进 span
...
burst_duration_ns = now_ns - burst_started_ns # 包含了等待上游的时间
burst_started_ns 在 burst 开始时取一次,而 burst 期间大部分时间在 await upstream.__anext__() 上等待。因此 legacy 口径度量的是"从 burst 开始到 本次 yield 的墙钟跨度",其中包含上游等待;它不等于"pump 同步占用了事件循环多久"。
ActivityTrace 过滤器侧存在同构的口径问题(filterMaxBurstDurationMs)。
本批次不删除、不改写这两个 legacy 读数(历史连续性),而是新增只统计同步工作量的 pumpMaxActiveBurstDurationMs / filterMaxActiveBurstDurationMs,并把两者的语义差异 写进诊断字段注释,避免下一次再被误读。
1.3 问题 B:consumer-drain 假超时,把 100% 完整的 Session 判成 partial
Build 67 的关闭诊断出现自相矛盾的一组值:
dataCompleteness = complete
ingressUndrained = 0
consumerDrainStatus = timed-out (≈500.824ms)
coreCloseoutStatus = timed-out
overallCloseoutStatus = partial
closeoutFailureStage = null <- 终端只能推导出 core-closeout-timed-out
closeoutFailureReason = null
没有任何数据丢失,却被判成 partial。 根因是分类缺陷而非数据不完整: Step 3 的 consumer drain 把全部 stream task 放进同一个 500ms 窗口等待:
# 旧行为
tasks_timeout = min(0.5, heavy_remaining_seconds() * 0.2)
if tasks: # <- tasks 里包含辅助任务
done_tasks, pending_tasks = await asyncio.wait(tasks, timeout=tasks_timeout)
而 tasks 里混着两类语义完全不同的任务:
| 任务 | 语义 | 睡眠周期 |
|---|---|---|
stream-activitytrace / stream-sysmontap / … | Source Consumer:真正从源拉 Raw | 无周期睡眠 |
startup-core-profile-flush | 启动 CoreProfile 交接(会真正影响数据完整性) | 事件驱动 |
stream-device-conditions | 条件源消费者 | 无周期睡眠 |
stream-target-monitor | 辅助:Identity 轮询 | asyncio.sleep(0.75) |
stream-sample-publisher | 辅助:Sample 发布 | asyncio.sleep(interval_ms)(~1.0s) |
一个睡 750ms 或 1000ms 的辅助任务,在任何短于自身睡眠的窗口里都不可能醒来。 于是两个健康的 sleeper 被记到了 500ms 的"consumer drain"账上,Session 被判 partial。
关键判断:这不是"窗口太小"。把 0.5s 改成 1.5s 只会掩盖误分类,同时让真正的 消费者停摆多等 1 秒——属于明确禁止的修法。分类才是修复。
2. 目标与非目标
2.1 目标
- Part A(可归因):为每条匹配的 FrameLifetime 记录七层 host 单调时间戳,
输出层间 delta 的分位数/Top-N 最差间隙,并在 host gap > 500ms 时输出紧凑的 displayPipelineGapDiagnostics,把间隙归因到 upstream-source / filter / subscription-queue / consumer / mixed。
- 区分源端不连续与 host 传输间隙:只能把
host_gap − source_gap 的超出部分算作 Perfowl 可能的缺陷。
- Part B(正确分类):把 stream task 拆成
source_consumer_tasks与
auxiliary_tasks;只有真正的 Source Consumer 未完成最后一次入队才允许造成 timed-out / partial。
- 修正误导口径:新增 active-duration 诊断,不改变公平性时钟。
- 保持轻量:诊断有界(样本 ≤4096/层、Top-N ≤32),不对热点路径引入
逐事件写盘、排序、锁或线程跳转。
- 正常关闭:Build 68 的 Stop → stopped 应 < 2s,且
overallCloseoutStatus=clean。
2.2 非目标(明确禁止)
- 禁止修改 FPS / FrameTime / P95 / Jitter / Refresh Rate 的任何公式。
- 禁止修改 ActivityTrace Source Owner。
- 禁止修改 FrameLifetime 白名单与解码器(含
GAP_REFRESH_MULTIPLE_THRESHOLD=12
与 source-gap 语义)。
- 禁止修改
MetricRegistry、CapturePlan、CoreProfile 策略。 - 禁止修改 Swift Core 的
gracefulTimeout = 10s。 - 禁止改变 Pmd3 pump fairness(32 events / 1ms)与 ActivityTrace filter fairness
(64 messages / 1ms)。
- 禁止 Graphics FPS 回退、CoreProfile 取代 FrameLifetime、
missing→0/16.67/60 填充、插值伪造、放大队列掩盖根因、延长 Host timeout、 重新引入 historical replay。
- 分层时间戳不得污染 canonical 指标语义:它是 diagnostics-only 证据,
推荐承载在 ActivityTraceTimingEnvelope / RawEventEnvelope.diagnostic_timing 一类的附加元数据上,不提升正式 raw schema 版本。
3. Part A:七层时间戳链与有界间隙归因
3.1 HostTimingChain(diagnostics-only)
perfowl_collector_core/contracts.py 新增 HostTimingChain,七个可选 Optional[int] 单调纳秒字段,按管线顺序排列:
| 层 | 字段 | 语义 |
|---|---|---|
| 1 | tap_callback_monotonic_ns | host 侧 tap 迭代器拿到消息后最早可观测边界 |
| 2 | filter_matched_monotonic_ns | 通过白名单判定 |
| 3 | subscription_enqueue_monotonic_ns | pump 入队 |
| 4 | subscription_dequeue_monotonic_ns | 消费者出队(__anext__) |
| 5 | adapter_yield_monotonic_ns | RawAdapter yield(== host_receive_monotonic_ns) |
| 6 | realtime_consume_monotonic_ns | realtime 消费入口 |
| 7 | ingress_accepted_monotonic_ns | OrderedRawIngress 接受入队 |
两条承重规则:
- 每个值都是 Perfowl 在 host 上读取的
time.monotonic_ns()。
tap_callback_monotonic_ns 是 Perfowl 能观测到的最早边界, 明确不是"设备产生该事件的时刻"——那个时刻在 host 侧不可观测, 不得被任何文档或字段名暗示。
- 这里的任何值都不是指标输入:不进 FPS / FrameTime / P95 / Jitter / Refresh
Rate 公式,不改变事件的产出集合,也不用于替代缺失值。
RawEventEnvelope 增加可选 host_timing 字段(schema 字符串不提升, 仍是 perfowl.raw-event/1)。序列化只在存在且非空时写入 hostTiming, 反序列化缺失时还原为 None——无损往返,且 R8-Fix-6 之前的 Session 记录 照常回放。
3.2 只包装匹配事件:TimedRawEvent
拒绝消息(非 FrameLifetime)是洪水级的,绝不能为它分配链条。 因此过滤器只对通过白名单的消息产出 TimedRawEvent(payload, host_timing); Pmd3Subscription 作为通用桥不导入任何 display 专用类,仅通过 duck-typed host_timing 属性查找打戳——一个没有链条的 item(其他所有源) 只付一次属性查找。
3.3 层间 delta
DisplayPipelineTiming 从链条计算七个 delta(单位 ms):
tapToFilterMs filter → 判定
filterToPumpEnqueueMs 判定 → pump 入队
pumpQueueWaitMs 入队 → 出队(队列等待)
dequeueToAdapterYieldMs 出队 → adapter yield
adapterYieldToRealtimeConsumeMs adapter yield → realtime 消费
realtimeConsumeToIngressMs 消费 → ingress 接受
tapToIngressMs 端到端
每层输出 P50 / P95 / P99 / Max 以及 >100ms / >500ms / >1000ms 计数。 负值 delta 视为链条 bug(非单调),直接丢弃,绝不污染分位数或 Max。
3.4 有界性
DISPLAY_PIPELINE_TIMING_HISTORY_CAPACITY = 4096 # 每层样本上限
DISPLAY_PIPELINE_GAP_TOP_N = 32 # 最差间隙上限
DISPLAY_PIPELINE_GAP_THRESHOLD_MS = 500.0 # 进入间隙历史的门槛
内存为「7 层 × ≤4096 样本的 deque」+「≤32 项的 heapq」,不随事件数增长。 每事件的工作量是若干次整数减法;没有逐事件写盘、日志、排序、锁或线程跳转。 分位数只在 snapshot() 时计算一次。
3.5 间隙归因:只有"超出真实源端不连续"的部分才可归责
Build 67 的 2878ms host gap 内含 ~599ms 真实源端呈现不连续, 因此"这个间隙是 host bug"不成立。归因规则是减法式的:
excess_ms = host_gap_ms - source_gap_ms
if excess_ms <= 1.0: # 测量噪声 / 源端已完全解释
return "upstream-source"
if tap_callback_delta_ms >= host_gap_ms * 0.8:
# 最早可观测边界上间隙已经存在 → Perfowl 的后续层没有新增它
return "upstream-source"
# 否则由占超出部分最大份额的层认领(≥60%),否则诚实记为 mixed
displayPipelineGapDiagnostics 输出 Top-N 最差间隙,每条包含 frameSeed / sourcePresentationGapMs / hostReceiveGapMs / hostAttributableGapMs / tapCallbackDeltaMs / 七个层 delta / classifiedLayer / quality。classifiedLayer ∈ {upstream-source, filter, subscription-queue, consumer, mixed}。
必须区分「源端呈现不连续」(sourcePresentationDeltaMs,设备真实掉帧) 与「host 传输间隙」(Perfowl/host 侧多花的时间)——两者不得混为一谈。
4. Part B:Closeout 任务分类修复
4.1 任务分类
stream_candidate_session() 内部新增两个桶,在任务创建时分类:
source_consumer_tasks: list[asyncio.Task] = [] # 真正拉 Raw 的任务
auxiliary_tasks: list[asyncio.Task] = [] # 纯控制 / sleeper
register_task(task, consumes_raw=...) 统一登记;forget_task(task) 在三处清理点 同时从三个桶移除。分类结果:
| 任务 | 分类 | 理由 |
|---|---|---|
stream-<adapter> | consumes_raw=True | Source Consumer |
stream-device-conditions | consumes_raw=True | 条件源消费者 |
startup-core-profile-flush | consumes_raw=True | 启动 CoreProfile 交接,丢失会真实影响数据完整性;不是 sleeper(事件驱动,无周期睡眠) |
stream-target-monitor | consumes_raw=False | 纯 Identity 轮询(0.75s) |
stream-sample-publisher | consumes_raw=False | Sample 发布(~1.0s) |
4.2 两类任务用各自的语义收敛(drain_closeout_tasks)
perfowl_collector_core/closeout.py 新增共享原语 drain_closeout_tasks():
- Source Consumer:给一个有界窗口(
SOURCE_CONSUMER_DRAIN_TIMEOUT_SECONDS = 0.5,
不放宽)等待其完成最后一次入队;未完成的 cancel() 后按剩余预算有界 join。 真正的消费者超时意味着可上报的数据丢失——只有它能把 Session 判 partial。
- Auxiliary:立即
cancel(),然后在剩余预算内有界 join。
辅助任务不拥有任何 Raw,因此它"收敛慢"只值得记录,不能改变 Session 判决。
两阶段共用同一个绝对 CloseoutDeadline,因此无论哪一类任务如何表现, 都不可能延长 Stop → Process Exit 预算。
4.3 advisory 阶段:auxiliary-stop 不得翻转判决
CLOSEOUT_ADVISORY_STAGES = frozenset({"auxiliary-stop"})
def is_verdict_bearing_stage(name: str) -> bool:
"""True when a stage timeout must downgrade the Session verdict."""
return name not in CLOSEOUT_ADVISORY_STAGES
closeoutLedger.first_timeout() 的原始语义保持不回改;realtime 侧改为
ledger_first_timeout = next(
(stage for stage in closeout_ledger.entries()
if stage.status in ("timed-out", "abandoned")
and is_verdict_bearing_stage(stage.name)),
None,
)
即:advisory 阶段超时只记录、不降级。
4.4 诊断字段
build_stop_diagnostics 新增:
sourceConsumerTaskCount / sourceConsumerCompletedCount
sourceConsumerCancelledCount / sourceConsumerTimedOutCount
consumerDrainStatus
auxiliaryTaskCount / auxiliaryCancelledCount
auxiliaryStopStatus / auxiliaryStopDurationMs
closeoutWarning
判决规则:
- 真正的消费者超时 →
closeoutFailureStage=consumer-drain/
closeoutFailureReason=source-consumer-drain-timeout → partial。 优先级明确:上方的 durability 失败(writer / seal)更严重,先占位; 只在没有更严重失败时才由 consumer-drain 认领。
- 辅助任务超时但 Raw / writer / seal 均完整 →
closeoutWarning=auxiliary-stop-timeout,dataCompleteness=complete, overallCloseoutStatus 不是 partial。
4.5 pumpMaxBurstDurationMs 口径修正
- 保留 legacy:
pumpMaxBurstDurationMs/filterMaxBurstDurationMs(wall-span,含上游等待),
仅补注释说明它不是 event-loop 占用读数。
- 新增:
pumpMaxActiveBurstDurationMs/filterMaxActiveBurstDurationMs,
只累加 __anext__ 返回之后到本次 yield 决策之间的同步工作量; await upstream 被明确排除。
- 公平性时钟不变:仍是 32 events / 1ms(pump)与 64 messages / 1ms(filter),
burst 计数与时间边界一行未改。
5. 实施记录(Implementation Update)
实际修改范围(R8-Fix-6 自有文件):
| 文件 | 改动 |
|---|---|
perfowl_collector_core/contracts.py | 新增 HostTimingChain(ORDER / RECORD_KEYS / observed() / stamp() / to_record() / from_record())、TimedRawEvent;RawEventEnvelope.host_timing(schema 不提升)与无损往返 |
perfowl_collector_core/pmd3_backend.py | Pmd3Subscription 新增 pump_max_active_burst_duration_ms;_pump() 测量 active span 并打 subscription_enqueue_monotonic_ns;__anext__ 打 subscription_dequeue_monotonic_ns;_stamp_timing() duck-typed 通用打戳 |
perfowl_collector_core/display_performance.py | 新增 DisplayPipelineTiming + 七个 delta 定义 + classify_display_pipeline_gap() + 有界聚合辅助;ActivityTraceAcquisitionCensus 新增 filterMaxActiveBurstDurationMs;_ActivityTraceFilteredStream 只对匹配消息产出 TimedRawEvent 并测量 active span;adapter 暴露 display_pipeline_timing(),census 快照加入 timing / largestGaps |
perfowl_collector_core/realtime_ingress.py | display 快路径打 ingress_accepted_monotonic_ns |
perfowl_collector_core/realtime.py | source_consumer_tasks / auxiliary_tasks 分类与 register_task / forget_task;diplay 快路径解析 display_pipeline_timing 并把链条折叠进有界聚合;Step 3/3b 收敛为 drain_closeout_tasks();ledger_first_timeout 跳过 advisory 阶段;closeoutFailureStage=consumer-drain 归因;closeoutWarning 与 consumer/auxiliary 诊断字段;manifest 新增 displayPipelineGapDiagnostics |
perfowl_collector_core/closeout.py | 新增 CLOSEOUT_ADVISORY_STAGES / is_verdict_bearing_stage() / SOURCE_CONSUMER_DRAIN_TIMEOUT_SECONDS / AUXILIARY_STOP_TIMEOUT_SECONDS / AUXILIARY_STOP_STATUS_TIMEOUT / CloseoutTaskDrainResult / drain_closeout_tasks() |
相对原方案的偏差与原因:
HostTimingChain.stamp()集中"首个写入者获胜"规则。
方案最初在每个调用点用 if ... is None 守卫直接赋值;实现改为唯一的 stamp(field, ns) 原语,所有层(含 duck-typed 的 _stamp_timing)都走它。 原因:把"绝不覆盖更早观测"的规则收敛到一处,既避免调用点遗漏,也让测试可以 直接验证产品实际使用的那一个原语。
drain_closeout_tasks()抽成closeout.py的共享原语。
方案最初把 Step 3/3b 内联在 realtime.py 的闭包里;实现抽成独立、可单测的 异步原语并返回 CloseoutTaskDrainResult。 原因:内联闭包无法独立验证,而"分类是否正确"恰恰是本批次的核心; 抽出来既便于独立验收,也让两阶段共用同一 deadline 的关系显式化。
WriteOutput/emit()等其他文件不在本批次范围内,
共享工作区中其他并行批次的未提交改动(frame_derivation.py / metric_engine.py / online_report.py / recording.py / CollectorSupervisor.swift / 构建脚本 / 若干测试)未被本批次触碰。
当前状态:implemented · gate-open;E2 completed / E4 pending。
6. 测试与验证(Validation Update · 2026-09-19 · E2)
新增两个专项测试文件(Python 3.12):
tests/test_display_pipeline_timing.py(31 项)- Test A pump active duration:上游 await 不计入 active(legacy > 3ms vs active < 1ms);
active 恒 ≤ wall-span;pump/consumer 双向打戳有序;无链条的普通 item 不被改动。
- Test B filter active duration:tap 等待不计入 active;仪表化不改变公平性;
只有匹配消息携带链条,拒绝洪水零链条。
- Test C 分层时间戳有序性:七层按
ORDER打戳且单调;首个写入者获胜;
未知层抛错;record 无损往返;schema 仍为 perfowl.raw-event/1; 缺失 → None;层间 delta 可重建端到端 delta; 集成:真实 filter + Pmd3Subscription + OrderedRawIngress 端到端七层齐全且有序。
- Test D 合成注入层延迟分类:源端已完全解释 / tap 边界已显示间隙 →
upstream-source;
注入 filter / queue / consumer 延迟分别归因到对应层;无主导层 → mixed; Build 67 形态(2878ms host gap + 599ms 源端不连续)归因 upstream-source; 低于 500ms 门槛的间隙不进入历史。
- Test E 有界内存:200000 事件后
observedEventCount=200000、
retainedSampleCount 恒为 7 × 4096 = 28672、largestGaps ≤ 32、 RSS 增长 < 32MB;5000 与 200000 事件的保留足迹相等(不随事件数线性增长); Top-N 只保留最差间隙。
- Test J 公平性防回归:576 事件仍按 32 边界 yield;200000 条带仪表事件
公平性保持且打戳完整;200000 条拒绝洪水仍按 ≥64 边界 yield。
- 120Hz benchmark:7200 条 FrameLifetime(60s @120Hz)逐帧聚合,
单帧聚合开销 < 0.5ms(远低于 8.33ms 帧预算); 10 条注入 1100ms 消费者停顿全部被归因 consumer; 8.333ms 的常规到达间距不进入间隙历史。
tests/test_closeout_task_classification.py(11 项)- Test F consumer / auxiliary 分离:快速的 consumer 完成,750ms sleeper 被
cancel 而非等待(用时 < 0.5s);空集合为 skipped 而非 timed-out; 诊断字段两类齐全;auxiliary-stop 属 advisory,其他数据/durability 阶段仍为 verdict-bearing。
- Test G 真实 consumer 超时:无法完成最后一次入队的消费者仍
timed-out,
且是 verdict-bearing(consumer-drain);窗口未被放宽(仍为 0.5s); 窗口被绝对 deadline 裁剪(重预算耗尽时 < 0.05s 而非新的 500ms)。
- Test H 顽固 auxiliary:拒绝收敛的辅助任务被有界 join(< 1.2s),
记为 auxiliary-stop-timeout,consumerStatus=completed, 不产生 verdict-bearing 超时。
- Test I Build 67 关闭形态回归:先复现旧行为(500ms 窗口下恰好 2 个 pending
sleeper → 假 timed-out),再验证新行为 (consumerStatus=completed、两个 auxiliary 被 cancel、无 verdict-bearing 超时、 用时 < 0.5s);健康 consumer + 顽固 auxiliary 的组合只产生 advisory 警告。
验证结果:
Python 3.12 全量(共享工作区,含并行批次测试) 696 / 696 OK (44.033s)
- test_display_pipeline_timing 31 / 31 OK
- test_closeout_task_classification 11 / 11 OK
Swift 全量 见下方门禁
站点(知识门禁 + VitePress build) 见下方门禁
git diff --check PASS(无空白错误)
静态不变性(G1–G17 核对):本批次未修改
- FPS / FrameTime / P95 / Jitter / Refresh Rate 公式;
- ActivityTrace Source Owner;
- FrameLifetime 白名单与解码器(含
GAP_REFRESH_MULTIPLE_THRESHOLD=12); MetricRegistry/CapturePlan/ CoreProfile 策略;- Swift Core
gracefulTimeout = 10s; - Pmd3 pump fairness 32 events / 1ms;
- ActivityTrace filter fairness 64 messages / 1ms;
RawEventEnvelope.SCHEMA(仍为perfowl.raw-event/1)。
7. 遗留项与下一阶段
- 本批次不构建 Build 68、不执行真机 E4、不声明
validated。 - Build 68 真机 E4 需要验证:
displayPipelineGapDiagnostics.largestGaps[*].classifiedLayer能把残余间隙
明确归因到某一层(或诚实记为 mixed / upstream-source);
- 正常 Stop → stopped < 2s,且
overallCloseoutStatus=clean、closeoutWarning=null、 consumerDrainStatus=completed;
- 若出现辅助任务超时,
dataCompleteness仍为complete且 overall 不是 partial; sourceConsumerTimedOutCount=0(除非确有消费者真的停摆)。
- 关联文档:R8-Fix-5 / 5.1 / 5.2 的结论不回改,本批次只在各自文末追加带绝对日期的
Validation Update 增量段。
- 知识库仅在
hostReceiveDeltaMs被描述为"DTX 回调到达时刻"时才修正——
该字段实为 adapter 观察到的到达时刻,最早可观测边界是 hostTiming.tapCallbackMonotonicNs。