wandering1
f754d59218
分层：流程与规范/ 单元测试/ 板级测试/ 专项验证/ 测试工具/ 测试数据/， 顶层只留新增的目录导航 README.md（归层判据 + 硬约束 + 本次处置记录）。 - 搬迁 28 个路径：测试数据三个目录 58 个文件为纯改名（R100，内容逐字节不变） - 全库引用同步 124 个文件：AGENTS / docs 索引 / skills / 门禁注释 / scripts - 门禁面：scripts/check_test_traceability.py 的 glob 改 rglob （分层后不递归扫描＝追溯门禁直接瞎掉） - scripts/rename_ref.py：收尾的 ℹ 提示在 GBK 代码页抛 UnicodeEncodeError， 让进程以退出码 1 收场而改写其实已落盘（RC 与真实结果相反）；改为把 stdout/stderr reconfigure 成 UTF-8，与 check_doc_links.py 等同法 - docs/文档规范.md §1.1 补「子目录文件过多时再分一层」；§3.6 补 rename_ref 搬整目录的两个实测坑：① 会改写目录内部文件的内容 ② 内部文件的 ../ 出链 不补层级（本次 23 个被误改的证据文件已按 HEAD 原始字节逐字节还原） - docs/README.md §6 改为与六个子目录一一对应，并补登原先漏登记的 「启动日志原子性复验流程」一行 - .cubemx_survival_baseline.json：App/util/task_watchdog.c 的注释路径也随分层更新， 该文件是存活审计的 watchdog-module 漂移锚点，按脚本自己的提示跑 --write 重建基线 （实测重建后仅 watchdog-module 一条哈希变化） - 铁律 4 例外（本次在任务树里改了单写者文件）：AGENTS.md 与 .pre-commit-config.yaml 只被 rename_ref 改写路径字面量（后者全在注释行）， 任务表块与钩子声明一字未动 验证：check_doc_links.py --sections-strict 覆盖全部 88 个改动 .md 全绿； check_test_traceability.py 输出与主树逐行一致；196 个文本文件无 BOM、无新增 CR、无 U+FFFD、无行尾空白；陈旧引用面由主树 25 处降到 6 处（无新增断链）。
121 lines
7.8 KiB
Markdown
121 lines
7.8 KiB
Markdown
# M2 链路延迟实测数据（Phase 13，安静档）
|
||
|
||
本目录保存 M2（Phase 13：芯片 + 队列时延基线）的**原始实测产物**。判定阈值与解读见
|
||
[`../../专项验证/链路延迟测试说明.md`](../../专项验证/链路延迟测试说明.md) §6.2；缺陷总表见 `docs/测试说明/专项验证/链路延迟测试说明.md` §8。
|
||
|
||
## 1. 运行元数据
|
||
|
||
| 项 | 值 |
|
||
|---|---|
|
||
| 日期 | 2026-09-22（设备 RTC 显示 2026-09-21，落后 1 天，仅显示差异；主机时间戳 = 设备 + 4s） |
|
||
| 台架 | COM6 @115200；目标 192.168.1.100:8080（Phase 13 独占 socket 2） |
|
||
| 固件 | `test/board/test_config.h` = `TEST_SUITE_CH395F`；`test/board/ch395f_test.h` = `ENABLE_PHASE13_TESTS`（仅此一项） |
|
||
| 构建 | `keil-build` skill（`keil_build.py`）→ **0 错误 0 警告**（测试构建与产品构建均 0/0） |
|
||
| 对端 | `.venv\Scripts\python.exe test/host/latency_peer.py --mode net`（纯标准库，`--wait 170`） |
|
||
| 会话顺序 | HELLO → L5_RECV → L5_SEND → L3 → L10 → L6 → L7 → DONE |
|
||
| 干扰 | 无（安静档，`ftp_stress=0`；未跑 `--ftp-stress`） |
|
||
| PASS 轮次 | **run12 / run13 / run15** 三次独立完整 PASS（`summary verdict=OK`、`=== Phase 13: 1/1 PASSED (failed=0) ===`、peer exit 0） |
|
||
|
||
复现命令（顺序不可反：先 `clear` 再起 peer，最后烧录）：
|
||
|
||
```powershell
|
||
& '.venv\Scripts\python.exe' .dsh\skills\keil-build\scripts\keil_build.py
|
||
& '.venv\Scripts\python.exe' .dsh\skills\serial-assistant\scripts\serial_tool.py clear
|
||
& '.venv\Scripts\python.exe' test\latency_peer.py --host 192.168.1.100 --port 8080 `
|
||
--json "docs\测试说明\测试数据\m2_data\m2_quiet_runNN.json" --wait 170 # 后台作业
|
||
& '.venv\Scripts\python.exe' .dsh\skills\stlink-flash\scripts\stlink_flash.py flash
|
||
& '.venv\Scripts\python.exe' .dsh\skills\serial-assistant\scripts\serial_tool.py wait-idle `
|
||
--timeout 120 --settle-ms 10000 --max-ms 110000
|
||
# 判定：Grep .dsh\skills\serial-assistant\scripts\state\serial.log
|
||
```
|
||
|
||
判定标记：Required `App init OK` / `Network Init` / `net init: OK` / `[LAT] report complete` /
|
||
`=== Phase 13: 1/1 PASSED`；Forbidden `HardFault` / `assert` / `[ERR]` / `[FAIL]` / `verdict=FAIL`；
|
||
peer 侧退出码 **0** = PASS（收到 `0xFF` 并打印汇总，`l7_crc.fail == 0`）。
|
||
|
||
## 2. 产物清单
|
||
|
||
| 文件 | 内容 |
|
||
|---|---|
|
||
| `m2_quiet.json` | **run15**（最终代码，规范基线）peer 端原始 JSON，含 10 帧逐帧批次明细 |
|
||
| `m2_quiet_run13.json` | **run13**（PASS 复现）peer 端原始 JSON |
|
||
| `m2_quiet_run14.json` | **run14**（PASS；但该轮 MCU 侧探针日志过载，仅 peer 侧数据有效，见 §6） |
|
||
| `m2_serial_excerpt_run15.txt` | **run15** 串口证据片段 62 行（**只含烧录重启后的会话**：从 Phase 13 横幅/`run_id` 校准行到 `1/1 PASSED` + relisten） |
|
||
| `m2_serial_excerpt_run13.txt` | run13 串口日志中 `[LAT]`/`[NET]`/Phase 13 相关 87 行（含烧录前旧固件段，需自行忽略） |
|
||
|
||
## 3. 实测结果
|
||
|
||
### 3.1 MCU 侧（`[LAT]` 报告，三次 PASS）
|
||
|
||
| 段 | run12 med（min/max, n） | run13 med（min/max, n） | **run15 med（min/max, n）** | warn / crit |
|
||
|---|---|---|---|---|
|
||
| `queue_rt_recv` | 6014µs（5365/6020, 19） | 6007µs（5392/6025, 20） | **5997µs（5513/6033, 20）** | 10ms / 100ms |
|
||
| `queue_rt_send` | 986µs（836/1204, 20） | 987µs（833/1209, 20） | **987µs（838/1209, 20）** | 10ms / 100ms |
|
||
| `chunk_wait` | 235µs（215/238, 64） | 219µs（213/377, 64） | **219µs（214/381, 64）** | 10ms / 500ms(spike) |
|
||
| `logtax_line` | 4396µs | 4396µs（4390/4414） | **4396µs（4394/4422）** | 10ms / 25ms |
|
||
| `req2first_mcu` | 310µs（296/338, 10） | 318µs（263/361, 10） | **319µs（308/338, 10）** | 20ms / 200ms |
|
||
| `fullframe_mcu` | 6021µs（5986/6103, 10） | 6052µs（5966/6078, 10） | **6028µs（5991/6066, 10）** | 50ms / 500ms |
|
||
|
||
三轮均：6 段 `verdict=OK`、`spikes=0`、`summary verdict=OK`、`1/1 PASSED`。
|
||
|
||
> run12 的 `queue_rt_recv` n=19 而非 20：对端 20×100B 中相邻两包被 TCP 合并成一次收
|
||
> （完成判定按字节 2000B），属正常合并，非丢包（三轮字节数均为 2000）。
|
||
|
||
### 3.2 PC 侧端到端（peer JSON）
|
||
|
||
| 段 | run12 med（min/max） | run13 med（min/max） | run15 med（min/max） | CRC |
|
||
|---|---|---|---|---|
|
||
| L6 端到端（op→回显） | 12.5ms（5.5/16.0） | 13.8ms（5.9/16.0） | 8.9ms（6.3/16.0） | — |
|
||
| L7 首字节 | 10.9ms（7.9/16.2） | 11.8ms（7.5/17.7） | 11.3ms（7.8/16.5） | — |
|
||
| L7 全帧 3209B | 61.1ms（54.2/61.5） | 61.7ms（59.9/70.9） | 57.9ms（52.6/72.3） | 10/0 |
|
||
|
||
## 4. 关键发现：L7 尾批固定迟到 ~44~60ms
|
||
|
||
run15 逐帧明细（10/10 帧结构完全一致）：
|
||
|
||
```
|
||
frame#1: first=11.620ms batches=[1024,1024,1024,137] tail_lag=+53.8ms
|
||
frame#2: first=11.327ms batches=[1024,1024,1024,137] tail_lag=+46.5ms
|
||
frame#3: first= 8.160ms batches=[1024,1024,1024,137] tail_lag=+46.5ms
|
||
frame#4: first= 7.773ms batches=[1024,1024,1024,137] tail_lag=+44.8ms
|
||
frame#5: first= 9.858ms batches=[1024,1024,1024,137] tail_lag=+53.9ms
|
||
frame#6: first=11.900ms batches=[1024,1024,1024,137] tail_lag=+43.8ms
|
||
frame#7: first=10.465ms batches=[1024,1024,1024,137] tail_lag=+44.2ms
|
||
frame#8: first=10.615ms batches=[1024,1024,1024,137] tail_lag=+43.4ms
|
||
frame#9: first=11.328ms batches=[1024,1024,1024,137] tail_lag=+60.2ms
|
||
frame#10:first=16.522ms batches=[1024,1024,1024,137] tail_lag=+55.7ms
|
||
```
|
||
|
||
- 前 3 批各 1024B 在 **~4ms** 内到齐；第 4 批 137B（=3209−3072）稳定落在 **+43~+60ms**；
|
||
- MCU 侧把整个 3209B 交给芯片只花 **6.0ms**（`fullframe_mcu`）→ 延迟**不在 MCU 发送路径**；
|
||
- 缺口在**芯片 TCP 尾段发送 / 对端 ACK 交互**（候选：Nagle 式小段等待 + 对端延迟 ACK）；
|
||
- 该尾批**主导整帧时长**（total ≈ 首字节 + 尾批延迟），是远端显示"每帧多 ~50ms"的直接来源；
|
||
- **M3 待办**：Wireshark（`tcp.port==8080`）确认尾段是被芯片扣住还是被对端 ACK 拖住，再定对策
|
||
（对端 `TCP_NODELAY` / 帧长与 chunk 对齐），**未证实前不改协议**。
|
||
|
||
## 5. 结论（回答 M2 立项问题）
|
||
|
||
1. **安静档不存在 500ms 台阶**：三轮 6 段全 OK、零尖峰、p95≈med；
|
||
2. 会话级 MCU 净成本量级 **~6ms**（`queue_rt_recv`，与 netTask 轮询节拍同量级）；
|
||
3. 芯片 chunk 级不是瓶颈：`chunk_wait` med 219µs ≈ 每 chunk SPI 成本（1.61ms）的 1/7；
|
||
4. 生产链路的可见延迟主要在 **PC/线路段**（L6：MCU 侧 0.32ms vs 端到端 8.9~13.8ms）
|
||
与 **L7 尾批 ~50ms**。
|
||
|
||
## 6. 测量方法学（两条必须记住的坑）
|
||
|
||
1. **探针不得在 net 热路径逐调用打日志**（run14 实证）：在 `net_wait_result` 内加
|
||
`pick/block` 两行后，日志量 40KB → 1.04MB（9,644/9,779 行 = **98.6%**），115200 下
|
||
丢行/串行错位，冲掉 `[LAT]` 段证据，`wait-idle` 永远判不出空闲；并实测把
|
||
`queue_rt_send` med 从 987µs 抬到 **7685µs（7.8×）**、`queue_rt_recv` p95 抬到 21ms。
|
||
→ 该轮 MCU 侧数据**不作基线**；诊断需求改在 `[LAT]` 段报告侧聚合。
|
||
2. **首连必失败是有意为之的正常现象**：peer 首连时常在 MCU 启动期完成握手，随后芯片
|
||
空闲超时（15~30s 无数据）RST → `WinError 10054`；peer 自动 +2s 重连后会话正常
|
||
（run12/13/15 均如此）。**另注意**：首连时若 MCU 正在烧录，attempt1 由**上一版固件**
|
||
服务（日志里那段偏高的数据不属于本轮固件），只有烧录重启后的会话才计入本轮基线。
|
||
|
||
## 7. 未纳入本目录的数据
|
||
|
||
- run1~run11 为缺陷定位过程（D11~D16 见 `docs/测试说明/专项验证/链路延迟测试说明.md` §6.1），其中 run10/run11 的 L7 失败、
|
||
run9 的 170s 连接拒绝均已定位并修复；
|
||
- 压力档（`--ftp-stress` 复现）与 `--mode remo`（生产 RemoDispBus 客户端）属 M3。
|