外观
R8 · Display Performance Source Ownership 与 Gap Classification 收口
背景
Session 5c3a61d4-d6f3-4a92-8e17-b9bef32d65b3(iPhone17,3 / iOS 18.2.1, 2026-09-18 10:35-10:36,目标 App 百度网盘)暴露四个 P0 根因:
ios.foreground.fps同时存在pmd3.graphics.raw与pmd3.activity-trace.frame-lifetime.raw两个事实来源(Registry 契约已声明 ActivityTrace 单一所有权,但metric_engine.py::_graphics_metrics仍在从CoreAnimationFramesPerSecond投影同一个 metricID)。- Live FPS 用
hostNow - lastHostReceiveTime外推 source-time 窗口,Host 静默 ≥2s 即判定candidate-idle/FPS=0;真机证实 ActivityTrace host 交付 可批量延迟达 ~6.7s,源端仍以 ~16.6ms 正常节奏出帧。 FrameLifetimeDecoder仅验证prev_frame == previous.end_time的结构连续 性即标记quality=valid并计算 FrameTime,未验证该 interval 相对refresh_interval是否是一个合理的单帧/少帧间隔;真机记录了两次异常 (deltaSeed=64/presentationDelta=2879.367ms、deltaSeed=31/ presentationDelta=29876.021ms),仍被标记valid并进入 FrameTime/P95/ Jitter 统计。- Offline Frame Report(
analyze_display_frames)与 Live (DisplayPerformanceProjector)虽然共享同一个 decoder 产出的quality字段,但两侧对该字段的下游处理不完整,导致sourceGapCount=0与averageFrameTimeMs=1740.61ms同时出现。
已落地
- Phase A:
metric_engine.py::_graphics_metrics不再投影ios.foreground.fps;Graphics 仅保留三项 GPU 利用率正式 metric。新增RealtimeMetricProjector._graphics_observed_fps作为 diagnostics-only 字段 (frame_continuity_telemetry()["graphicsObservedFPS"]),供旧版 CoreProfile FrameTime 新鲜度交叉诊断使用,不再进入 Registry/Report。 - Phase B:
DisplayPerformanceProjector.snapshot()移除用 host 时间外推 source clock 后直接判定 0 帧的逻辑;改为显式 freshness gate (FRESHNESS_STALE_HOST_GAP_NS,等于 FPS 窗口宽度 1s):host 静默超过该值时 返回quality=stale-source/value=None,不再伪造candidate-idle/0。 - Phase C:
FrameLifetimeDecoder.decode()新增GAP_REFRESH_MULTIPLE_THRESHOLD=12(约 200ms@60Hz)的动态 gap gate:结构 连续但presentationDelta / refreshInterval超过该倍数时标记quality=source-gap、frameTimeMs=None,并强制下一条 event 重新 warmup (_pending_gap_rewarm),不允许跳过锚点直接恢复valid。 - Phase D:decode() 输出新增 diagnostics-only 字段
frameSeedDelta/sourcePresentationDeltaMs/hostReceiveDeltaMs/deliveryLagDeltaMs/refreshMultiple,均不参与 FrameTime/FPS 公式。 - Phase E:Live 侧
_rolling_frame_times(P95/Jitter 输入)已通过 decoder 的quality/frameTimeMs门禁天然排除source-gap;补齐source-gapquality 到_latest_frame_quality更新分支,避免其被静默吞掉。 - Phase F:
analyze_display_frames(Offline Frame Report)新增source-gap分类分支与sourceGapEventCount/discontinuityCount/largestSourceGapMs/continuousSegmentCount/validIntervalCount/validCoverageSeconds诊断字段;averageFrameTimeMs等统计口径不再被跨 gap 的巨大 interval 污染。Live 与 Offline 共享同一枚 decoder 产出的quality字段,不存在两套独立维护的 continuity 规则。 - Phase G:新增
build_provenance.py:collectorCoreVersion/collectorCoreSHA256(对 collector-core 自身源码计算,不依赖构建脚本) 始终存在;perfowlVersion/perfowlBuildNumber/perfowlGitCommit取自 macOS App 启动时注入的环境变量(CollectorSupervisor.environment(for:)读取CFBundleShortVersionString/CFBundleVersion/PERFOWL_GIT_COMMIT)。RawSessionRecorder在 Session 开始时冻结一次并写入manifest.json.buildProvenance。
验证
- Python sidecar(冻结 CPython 3.12 x86_64 + pymobiledevice3 11.3.1): 564/564(含新增
test_e4_display_gap_regression.py11 项、test_build_provenance.py3 项回归)。 - Swift:182 项,181 通过;
testStoppedCoreWithoutDeliveryIsMarkedPartial为既有计时敏感 flake(单独运行必过,与本次改动无关,未新增/未修复)。 - 新增 E4 真机数据回归 fixture:真实 Session 的两处异常 (2879.367ms/29876.021ms gap、6689ms host 延迟 vs 16.641ms 源端间隔)已固化 为单元测试,防止回归。
R8-Fix(Build 62 真机复测后,2026-09-18)
Build 62 真机 Session 062995a9-6bbb-455e-b8bf-faa17622d558(iPhone17,3 / iOS 18.2.1,manifest 确认 collectorCoreVersion=r8-display-source-ownership.v1) 证明 R8 的偽装消除按设计生效——但也第一次暴露真正的 P0:数据源本身。
事实基线:60 秒内 Graphics 观察到约 58 FPS(graphicsObservedFPS), ActivityTrace FrameLifetime 却只交付 2 条(frameSeed 333211→333212, 第二条 FrameTime=16.639291ms、refreshMultiple=0.998、60.0024Hz,decoder/ timebase/公式全部正确)。20 个产品 sample 中 FPS 全为 null(missing 9 / stale-source 11),FrameTime 有效 1 个,P95/Jitter warmup——这正是 R8 期望 的诚实缺失,不再伪造。真正问题是 iOS 18.2.1 上 ActivityTrace 未形成可靠连续 实时流。
本轮不再动 Display 计算公式,改为诊断 + 修复暴露出的具体缺陷:
- P0 acquisition census:
_ActivityTraceFilteredStream在 source-edge 白名单之前插入ActivityTraceAcquisitionCensus,统计 totalMessageCount / frameLifetimeMatchedCount / frameLifetimeRejectedCount / rejectedIdentityTopN(subsystem/category/name) / first-last callback 时间 / rawCallbackRateHz / streamEnded;seal 时写入display-acquisition-census.json与 manifest.displayAcquisitionCensus。 下一次真机运行即可区分"tap 静默(raw≈2, streamEnded)"与"白名单漏掉真实帧 (raw≫2, rejectedIdentityTopN)"两种完全不同的根因——白名单本身保持不变。 - P1 prepare_transport:
ActivityTraceFrameLifetimeRawAdapter补prepare_transport()(声明为 start-time-activated),修复source_preparation把它标记transport-preparation-not-supported/preparationState=failed而运行时实际正常启动的自相矛盾。 - P1 host timestamp:
raw_events()捕获一次time.monotonic_ns(),同时 传给decode(host_receive_monotonic_ns=)与RawEventEnvelope,使 Phase D 的hostReceiveDeltaMs/deliveryLagDeltaMs在真机不再恒为 null。 - P1 coverage 门禁:online
INVALID_QUALITIES增加source-gap/delivery-gap/discontinuity/stale-source;online 与 offline frame summary 增加validIntervalCount/validCoverageSeconds/coverageSufficient/coverageReason(阈值 5 个有效 interval),避免"1 个 interval 仍报 Avg FPS 60"。数值字段保持数学正确,仅新增 coverage 判定。 - P2 provenance:
build_provenance.py优先读取构建期写入的collector_core_build_stamp.json(--add-data打进 bundle),frozen 环境 不再 glob 不到.py而退化成SHA256("")=e3b0c442…;build-sidecar-core.sh 写入该 stamp(含 SOURCE_HASH 与 git commit);build-app.sh 将PerfowlGitCommit写入 Info.plist,CollectorSupervisor.environment(for:)从 Info.plist 读取并透传PERFOWL_GIT_COMMIT。
验证:Python 全量 572/572(新增 test_display_acquisition_diagnostics.py 7 项、 test_build_provenance.py 更新);Swift 全量 183/183(+1 testCollectorSupervisorEnvironmentForwardsGitCommitProvenance)绿灯, testStoppedCoreWithoutDeliveryIsMarkedPartial 为既有 ~50% 计时敏感 flake (已在 clean HEAD 上复现同样 fail/pass 交替,与本次改动无关)。
验证:Python 全量 572/572;Swift 全量 183/183。
R8-Fix-2(Build 63 真机复测后,2026-09-18,status partial · E4 诊断)
Build 63 真机 Session 8f7ab912-92d4-4ec3-a7e7-9250ee3cf1c0(manifest 确认 perfowlBuildNumber=63、perfowlGitCommit=d4b6d76、collectorCoreSHA256= d54a752… 非空——P2 provenance 修复经 E4 验证;host delivery diagnostics hostReceiveDeltaMs=3354ms 实际写出——P1 修复经 E4 验证)。
acquisition census 一次性把根因定死,且与前一次 Session 完全不同:
| 层 | 062995a9 | 8f7ab912 |
|---|---|---|
| tap 生存 | 2 条 | 健全:5636 msg / 141Hz / streamEnded=false |
| 白名单 | — | 正确:reject 全为正当非 FrameLifetime(CAImageQueue/RenderInterval/Commit…) |
| FrameLifetime 匹配 | 2 | 652 |
| 到达 recorder | — | 仅 5(frameSeed 371816–371823) |
即:652 条可解码 FrameLifetime 送达,只有 5 条进入录制管线,647 条(99.2%) 在过滤器与 recorder 之间丢失。 决定性证据(E4):
display.frame-lifetime.raw生事件 = 5(生事件无条件记录,非质量门问题,是 消费问题)。- 静默丢失:
droppedEventHighWater=0。647 条被泵入 2048 bound queue(<2048 不 溢出 drop),未被 drain,session 结束时丢弃。 - 非 throughput 律速:writer 在 28.66s 中约 20s(70%)空闲(>1s 空白 12 次)。
- display adapter 内部 sequence 只到 5 =
raw_events()只 yield 5 次;且 display task 既未 fail(firstFatalSource=None)也未 complete(streamEnded=false)→ session 结束时仍在运行/阻塞。 - FTI-008 既有诊断吻合:
frameTimeMissingWhileGraphicsFPSPositiveCount=14。
因果链:source 健全(652) → recorder 消费 5 → live projector 也只收 5 → metrics.csv 20 sample 中 FPS 0/20、FrameTime 3/20 → UI 空白(Refresh Rate 仍出,因其由 refresh_interval 单独算出)。
本轮实现(观测性 + 修复必要前置)
用户批准"再现 fixture → 修复"。离线再现(test_display_acquisition_diagnostics.py 的 SubscriptionBacklogAccountingTests)证明 **pump + consumer + writer_async_lock
- 单 worker executor 的隔离模式本身会完整 drain(650/650)**——即 starvation 是 full multi-source orchestration 固有,离线无法复现(依赖真机 asyncio 时序)。因此 先落地"把静默丢失变成可测量、精确定位 drain 停止边界"的观测性,而非盲改调度器 (AGENTS.md 效率/诚实门禁):
Pmd3Subscription新增delivered_event_count/consumed_event_count/undrained_at_close/pending_event_count;__anext__两个返回路径都计入 consumed,_pump计入 delivered,aclose记录 queue 深度。ActivityTraceFrameLifetimeRawAdapter.acquisition_census()附带 subscription 区块;并在stop()丢弃 subscription 引用前快照(修复一个同批发现的真机 bug:stop 先置 None 导致 seal 时读到 None,实机计量本会失效)。- 因此 Build 64 的
display-acquisition-census.json.subscription将直接给出deliveredEventCount(应≈652)与undrainedAtClose(应≈647),把"消费者 starvation"从推断变为实测,用于定向修复并提供前后对比证据。
修改文件:pmd3_backend.py、display_performance.py、 tests/test_display_acquisition_diagnostics.py。验证:Python 574/574;离线再现 测试 PASS(隔离模式完整 drain,实机 shape「5/652 + undrained>600」被单测固化)。
未关闭门禁
- 下一步优先(需真机):用 Build 64 重跑真机,读取
display-acquisition-census.json.subscription。确认undrainedAtClose≈647后,定向修复 consumer 的 multi-source drain 公平性(候选:display 高频源专用 drain 批量/独立 writer 通道/close 前 drain backlog),并用真机前后对比consumedEventCount验收(效率门禁要求前后证据)。 - 交付门禁:本批为
partial。ad-hoc 签名 Build 64 仅供真机诊断;Developer ID 签名/公证/stapling 未做(凭据缺失,blocked)。双远程推送与企业微信 Webhook 通知待用户确认后执行(外发操作)。 - Display-only / Startup+Display / 静态动态切换三场真机验收仍开放。
R8-Fix-3(Build 64 根因闭环 + 非阻塞 Wire 修复,2026-09-18,status implemented · gate-open)
Build 64 的两轮真机诊断把 R8-Fix-2 的“consumer starvation”进一步收敛到了单一高置信度根因:collector 在 asyncio 事件循环线程上同步写 stdout wire,Host 读取稍慢时 OS pipe buffer 填满,print(..., flush=True) 阻塞整个事件循环。 这会同时冻结所有 source consumer;ActivityTrace 本身继续把 FrameLifetime 泵入 subscription queue,但 raw_events() 无法继续 __anext__(),最终形成数百条 undrained backlog。
Build 64 决定性 E4 证据
两轮 Session 均确认 tap/source 健全、白名单正确、queue 无 high-water drop,但 consumer 几乎停止:
| Build 64 样本 | raw callback | FrameLifetime delivered | consumed | undrainedAtClose | dropped |
|---|---|---|---|---|---|
| A | 4454 msg / 123.00 Hz | 548 | 4 | 544 | 0 |
| B | 3270 msg / 107.95 Hz | 430 | 2 | 428 | 0 |
这与实测时序完全吻合:早期有少量正常数据,随后所有 source 都出现数秒级停顿;Display 高频源最先在 bridge queue 中积压,因此 FPS/FrameTime 最明显地表现为 missing。离线的普通 pump + consumer fixture 不复现,是因为它没有真实的慢 stdout pipe。
根因离线复现
使用“无 reader / 慢 reader 的 pipe + event-loop 线程同步 os.write”做最小复现时,pipe buffer 填满后整个 loop 直接挂住,连 consumer timeout/heartbeat 都无法继续推进。该行为与真机“每 5~10 秒才恢复一小段”的模式一致:真机 Swift 端并非永久不读,而是读取速度不足时周期性解除 pipe back-pressure。
最终修复
perfowl_collector_core_cli.py 新增 _WireOutput:
- 所有 collector → Mac App NDJSON wire 写操作移到独立 daemon writer thread;asyncio capture loop 的
emit()只做 JSON 编码 + 内存队列入队,不再执行任何阻塞 stdout I/O。 - buffer 同时按条目数(默认 256)和内存(默认 2 MiB)有界;高频
sample是实时快照,可在背压时丢弃/合并旧 sample,raw event 与最终报告仍独立落盘,不受 wire sample drop 影响。 hello / ready / capabilities / control_rejected / stop_requested / capture_stopped / finalizer_progress / report_sealed / stopped / error等控制/生命周期记录不可丢,并保持入队顺序。- 相邻 pending sample 会 coalesce 为最新快照,避免 Host 恢复读取后重放长时间过期 UI sample。
capture_stopped后主动清除尚未写出的旧 sample,使停止与 finalization 控制记录不被实时快照排队拖延。- writer pipe 错误只标记 sink failed,并继续清空内存队列;不能反向冻结 capture loop。
- 最终
stopped新增wireDroppedSampleCount/wireMaxBufferedCount/wireMaxBufferedBytes,供下一轮 E4 直接量化 host wire 背压。
E2 验证
_WireOutput专项:15/15 PASS;包含 writer 被故意阻塞时 caller 快速返回、sample coalesce、控制记录不丢、asyncio heartbeat 不被饿死。- Display / FrameTime / ActivityTrace 相关专项:118/118 PASS。
- Sidecar Python 全量:578/578 PASS(首次全量出现 1 项 Startup 时间敏感断言失败;同一项独立连续 5/5 PASS,第二次全量 578/578 PASS,判定为既有时序 flake,非本修复回归)。
下一轮 E4 验收(Build 65)
优先只跑一轮 30~60 秒 Display 动态场景,验收以下硬门禁:
text
display-acquisition-census.json.census.subscription
deliveredEventCount ~= frameLifetimeMatchedCount
consumedEventCount ~= deliveredEventCount
undrainedAtClose ~= 0
droppedEventCount = 0
metrics.csv
FPS 连续有值,不再 0/N 全 missing
FrameTime 连续有值
P95 / Jitter 达到 warmup 阈值后有值
wire stopped record
wireDroppedSampleCount 允许 > 0(表示 UI 快照在 host 背压下被诚实丢弃)
但 raw event / frame census / report coverage 不得因此缺失若该轮满足 consumed/delivered >= 99% 且 undrainedAtClose <= 1,即可关闭“stdout wire 阻塞导致 Display consumer starvation”这一根因;随后再做 Startup+Display 与静态/动态切换两场回归。当前状态:代码修复完成 E2,等待 Build 65 E4。
Validation Update · Build 65 (2026-09-18)
- R8-Fix-3 stdout hypothesis REFUTED as primary cause: Real device Build 65 test proved that adding
_WireOutput(asynchronous stdout queue) did not resolve the Display Source drain blockage or restore live FPS/FrameTime. - _WireOutput retained as defensive wire decoupling: Wire thread decoupling is retained to protect the event loop against slow JSON-RPC pipe readers, but is not the root cause of the Display performance gap.
- New primary direction: Source Drain ↔ Durable Writer coupling (R8-Fix-4). ActivityTrace high-frequency events were synchronously blocked by the slow disk persistence chain in
SessionWriter.append(). Detailed solution is documented in p4-r8-fix4-display-ingress-decoupling-plan.md.