[stats] output_bps / frame_bytes_max / sws_* 永远为 0(编码线程硬编码 timing 字段) #17

Closed
opened 2026-06-13 23:03:20 +08:00 by dailz · 2 comments
Owner

现象

所有 stats 行(80+ 条)中:

output_bps=0  frame_bytes_max=0  sws_p95=0.0ms  sws_avg=0.0ms

total_p95 永远等于 encode_p95(因为 total = sws + encode = 0 + encode)。

根因

src/state_portal.rs:651-655 编码线程上报 timing 时硬编码了三个字段中的两个:

let _ = timing_tx.try_send(EncodeThreadTiming {
    sws_us: 0,                  // ← 永远 0
    encode_us: elapsed,         // ← 仅此字段真实
    output_bytes: 0,            // ← 永远 0
});

src/stats.rs:142-145 直接把这些值推进统计向量:

self.sws_us.push(sws_us);              // 全是 0
self.encode_us.push(encode_us);
self.total_us.push(sws_us.saturating_add(encode_us));   // = encode_us
self.output_bytes.push(output_bytes);  // 全是 0

最终 output_bytes_per_secoutput_frame_bytes_p95output_frame_bytes_maxsws_* 全部失真。

影响

  • 无法从日志判断真实编码产出码率——只能从 write_h264: N bytes 反推
  • 无法判断单帧大小分布——keyframe 大小、P 帧大小、filler 帧大小无法区分
  • 无法判断 sws(像素格式转换)阶段耗时——排查编码瓶颈时缺关键数据
  • total_p95 误等同 encode_p95,扭曲对"编码总成本"的认知

修复方向

  1. encode_cpu_frame() 返回 (encode_us, sws_us, output_bytes) 或写入 EncodeThreadTiming 共享结构
    • sws_us:在 sws_scale 调用前后取 Instant::now() 差值
    • output_bytes:累加 packet 大小(pkt.sizepkt.data.len()
  2. state_portal.rs:651 改为透传真实值
  3. 顺便补 import_us(DMA-BUF → CPU 拷贝)的统计链路,目前 import 在另一处记录但未并入 encode thread timing

关联

  • 影响所有观测性相关的诊断能力
  • 修复后才能定量评估 #15、#19 的 filler 帧是否真的节省了带宽
## 现象 所有 stats 行(80+ 条)中: ``` output_bps=0 frame_bytes_max=0 sws_p95=0.0ms sws_avg=0.0ms ``` 而 `total_p95` 永远等于 `encode_p95`(因为 `total = sws + encode = 0 + encode`)。 ## 根因 `src/state_portal.rs:651-655` 编码线程上报 timing 时**硬编码**了三个字段中的两个: ```rust let _ = timing_tx.try_send(EncodeThreadTiming { sws_us: 0, // ← 永远 0 encode_us: elapsed, // ← 仅此字段真实 output_bytes: 0, // ← 永远 0 }); ``` `src/stats.rs:142-145` 直接把这些值推进统计向量: ```rust self.sws_us.push(sws_us); // 全是 0 self.encode_us.push(encode_us); self.total_us.push(sws_us.saturating_add(encode_us)); // = encode_us self.output_bytes.push(output_bytes); // 全是 0 ``` 最终 `output_bytes_per_sec`、`output_frame_bytes_p95`、`output_frame_bytes_max`、`sws_*` 全部失真。 ## 影响 - **无法从日志判断真实编码产出码率**——只能从 `write_h264: N bytes` 反推 - **无法判断单帧大小分布**——keyframe 大小、P 帧大小、filler 帧大小无法区分 - **无法判断 sws(像素格式转换)阶段耗时**——排查编码瓶颈时缺关键数据 - `total_p95` 误等同 `encode_p95`,扭曲对"编码总成本"的认知 ## 修复方向 1. `encode_cpu_frame()` 返回 `(encode_us, sws_us, output_bytes)` 或写入 `EncodeThreadTiming` 共享结构 - `sws_us`:在 `sws_scale` 调用前后取 `Instant::now()` 差值 - `output_bytes`:累加 packet 大小(`pkt.size` 或 `pkt.data.len()`) 2. `state_portal.rs:651` 改为透传真实值 3. 顺便补 `import_us`(DMA-BUF → CPU 拷贝)的统计链路,目前 import 在另一处记录但未并入 encode thread timing ## 关联 - 影响所有观测性相关的诊断能力 - 修复后才能定量评估 #15、#19 的 filler 帧是否真的节省了带宽
dailz added the area/encoderpriority/criticalarea/observabilitytype/bug labels 2026-06-13 23:03:20 +08:00
Author
Owner

Dependencies

Blocks:

  • #15 — stall 诊断需要 output_bps / frame_bytes_max 等真实 stats 数据
  • #18 — filler 浪费量化需要 stats
  • #20 — encoded_fps 钳制诊断需要 stats

建议优先修复本 issue。修好后 #15 / #18 / #20 都可以用量化数据诊断和验证。

## Dependencies **Blocks:** - #15 — stall 诊断需要 `output_bps` / `frame_bytes_max` 等真实 stats 数据 - #18 — filler 浪费量化需要 stats - #20 — encoded_fps 钳制诊断需要 stats 建议优先修复本 issue。修好后 #15 / #18 / #20 都可以用量化数据诊断和验证。
Author
Owner

已实现并提交 (0aba0e6)

按 Oracle 审核修正后的方案实现:54 insertions, 9 deletions, 2 文件。

根因

encode_thread_loop (state_portal.rs:651-655) 硬编码 sws_us: 0, output_bytes: 0encode_usInstant::now() 包裹整个 encode_cpu_frame 调用——把 sws 转换 + 编码混在一起,且 stats 面板永远显示 0。

修正方案

新增 SwEncodeTiming 结构体 (avhw.rs:40-48),含 Default derive:

pub struct SwEncodeTiming {
    pub sws_us: u64,       // NV12→YUV420P 转换
    pub encode_us: u64,    // avcodec_send_frame + drain
    pub output_bytes: usize, // libavcodec 产出的字节(即使下游 try_send drop 也计入)
}

drain_encoder 改返回 Result<usize> (avhw.rs:1297):

  • 新增 total_bytes 累加器
  • Muxer/Channel match 之前统一累加 pkt_size(Oracle 强调:避免分支重复 + 正确处理多 packet drain)
  • (*pkt.as_mut_ptr()).size 读取,guard > 0

encode_cpu_frame 三处改动 (avhw.rs:1115-1250):

  1. 入口 resetself.last_timing = SwEncodeTiming::default()——Oracle 指出的最大正确性陷阱:early return 路径(disconnect/pause/dedup skip)不会报告上一帧的 stale 值
  2. sws_us 测量Instant::now() 包裹 av_frame_make_writable + sws_scale
  3. encode_us 测量 + 构建结构体Instant::now() 包裹 avcodec_send_frame + drain_encoder,本地构建完整 timing snapshot 后一次性赋值 self.last_timing

take_timing() 方法 (avhw.rs:1112):

pub fn take_timing(&mut self) -> SwEncodeTiming {
    mem::take(&mut self.last_timing)
}

mem::take 返回并清零,防止重复读取 stale 值。

flush() 适配新签名:let _ = self.drain_encoder(start_ts)?;(忽略 flush 路径的字节数)

state_portal encode_thread_loop (state_portal.rs:646-656):

let t = encode.take_timing();
let _ = timing_tx.try_send(EncodeThreadTiming {
    sws_us: t.sws_us,
    encode_us: t.encode_us,
    output_bytes: t.output_bytes,
});

移除了外层 Instant::now() 和硬编码的 0。

Oracle 指出的 3 个陷阱均已规避

陷阱 规避方式
early return 路径读 stale timing 入口 last_timing = Default
flush() 通过 drain_encoder 污染 timing 状态 drain_encoder 返回 bytes,不在内部 mutate timing 字段
take_timing 不清零导致重复读取 mem::take 返回并清零

验证

  • cargo build 0 errors
  • cargo test 91/91 unit + 3/3 integration passed
  • cargo build --release

下一步

#19 (encoder spin 6s before WebRTC connect) — 依赖当前 timing 基础设施。

## 已实现并提交 (`0aba0e6`) 按 Oracle 审核修正后的方案实现:54 insertions, 9 deletions, 2 文件。 ### 根因 `encode_thread_loop` (state_portal.rs:651-655) 硬编码 `sws_us: 0, output_bytes: 0`,`encode_us` 用 `Instant::now()` 包裹整个 `encode_cpu_frame` 调用——把 sws 转换 + 编码混在一起,且 stats 面板永远显示 0。 ### 修正方案 **新增 `SwEncodeTiming` 结构体** (avhw.rs:40-48),含 `Default` derive: ```rust pub struct SwEncodeTiming { pub sws_us: u64, // NV12→YUV420P 转换 pub encode_us: u64, // avcodec_send_frame + drain pub output_bytes: usize, // libavcodec 产出的字节(即使下游 try_send drop 也计入) } ``` **`drain_encoder` 改返回 `Result<usize>`** (avhw.rs:1297): - 新增 `total_bytes` 累加器 - 在 `Muxer/Channel` match **之前**统一累加 `pkt_size`(Oracle 强调:避免分支重复 + 正确处理多 packet drain) - 用 `(*pkt.as_mut_ptr()).size` 读取,guard `> 0` **`encode_cpu_frame` 三处改动** (avhw.rs:1115-1250): 1. **入口 reset**:`self.last_timing = SwEncodeTiming::default()`——Oracle 指出的最大正确性陷阱:early return 路径(disconnect/pause/dedup skip)不会报告上一帧的 stale 值 2. **sws_us 测量**:`Instant::now()` 包裹 `av_frame_make_writable + sws_scale` 3. **encode_us 测量 + 构建结构体**:`Instant::now()` 包裹 `avcodec_send_frame + drain_encoder`,本地构建完整 timing snapshot 后一次性赋值 `self.last_timing` **`take_timing()` 方法** (avhw.rs:1112): ```rust pub fn take_timing(&mut self) -> SwEncodeTiming { mem::take(&mut self.last_timing) } ``` 用 `mem::take` 返回并清零,防止重复读取 stale 值。 **`flush()`** 适配新签名:`let _ = self.drain_encoder(start_ts)?;`(忽略 flush 路径的字节数) **`state_portal encode_thread_loop`** (state_portal.rs:646-656): ```rust let t = encode.take_timing(); let _ = timing_tx.try_send(EncodeThreadTiming { sws_us: t.sws_us, encode_us: t.encode_us, output_bytes: t.output_bytes, }); ``` 移除了外层 `Instant::now()` 和硬编码的 0。 ### Oracle 指出的 3 个陷阱均已规避 | 陷阱 | 规避方式 | |------|---------| | early return 路径读 stale timing | 入口 `last_timing = Default` | | `flush()` 通过 `drain_encoder` 污染 timing 状态 | `drain_encoder` 返回 bytes,不在内部 mutate timing 字段 | | `take_timing` 不清零导致重复读取 | `mem::take` 返回并清零 | ### 验证 - `cargo build` ✅ 0 errors - `cargo test` ✅ 91/91 unit + 3/3 integration passed - `cargo build --release` ✅ ### 下一步 #19 (encoder spin 6s before WebRTC connect) — 依赖当前 timing 基础设施。
dailz closed this issue 2026-06-14 08:51:55 +08:00
Sign in to join this conversation.