Skip to content

Commit a969fa4

Browse files
feat(test): stream, time and bound mcpp test (2026.8.1.1) (#327)
* feat(test): stream, time and bound `mcpp test` (2026.8.1.1) `mcpp test --workspace` did not report time, did not set a deadline, and did not flush. The three compound: a macOS CI lane spent 45 minutes in it, was killed by the job timeout, and left a log containing not one line of mcpp's own output — only the test binaries', which are separate processes that flush at their own exit. Attributing the stall meant reverse-engineering log timestamps. stdout: every status line was a bare std::println with no flush anywhere, and the repo had no setvbuf — so *when* output became visible was decided by each platform's libc buffer size, and that number differs everywhere: musl (the Linux release linkage) hardcodes BUFSIZ = 1024 and ignores st_blksize, Apple libc takes st_blksize which is 65536 for a pipe, MSVCRT uses 4096 and treats _IOLBF as _IOFBF. Measured on one 97-member workspace, the same 13 639 bytes of status output flushed 13 times on Linux and zero times on macOS. Fixed on both legs (setvbuf in main, ui::flush from every stdout writer): 3 block writes became 391 line writes. Timing: the clock started after the package build and the bulk test build, so `finished in` covered only the per-test loop — one member printed 6.53s against 93.5s actual, and the understatement is worst exactly on the build-heavy members where the number matters. It now starts before Phase A and reports `finished in 93.5s (build 87.0s + run 6.5s)`. Bounds: --timeout only ever covered the test *run*; all three ninja drives had no deadline at all, which is why a link that never returns could not be stopped by any --timeout value. Adds --build-timeout (per drive, default 900, POSIX only) and --workspace-timeout (whole fan-out), and makes --timeout default to 300 — `--timeout 0` still means no limit, it just has to be asked for. Fan-out: per-member M/N progress, per-test durations, per-member elapsed, a workspace-level summary and a `slowest:` list. JSON: the fan-out header used to escape for member #1 and be suppressed from #2 on, because run_tests set the quiet flag itself — one stream, two behaviors, and a stray non-JSON line. Silenced before the first member instead. Records are now member-qualified and the stream ends with a workspace_summary. Also surfaces the one silent platform difference in this path: macOS injects no runtime library path for test binaries (deliberately — DYLD_LIBRARY_PATH would reach every executable ninja launches), so a test needing [runtime] library_dirs fails there with a dyld error naming neither cause nor platform. Analysis and plan in .agents/docs/2026-07-31-test-workspace-observability-*.md. * fix(main): move the stdout buffering call into mcpp.ui `module;` opens a global module fragment, which is only legal in a module unit. main.cpp is not one, so the fragment introduced for <cstdio> made it ill-formed: GCC accepted it silently, Clang rejected it outright ("missing 'module' declaration at end of global module fragment") and every macOS job — where the toolchain is Clang — failed to build. The policy belongs in mcpp.ui anyway: that module already owns "when does output become visible", already has a legitimate global module fragment for <cstdio>, and already exports flush() for the Windows half of the same guarantee. Verified by building mcpp with llvm@22.1.8 locally, not just gcc — the class of bug this was is invisible to a single-compiler check. * fix(ui): do not call setvbuf on Windows — size 0 aborts the process The UCRT documents setvbuf's size as `2 <= size <= INT_MAX`. Zero goes through the invalid-parameter handler, whose default action terminates the process: 0xC0000409, which git-bash reports as a bare exit 127. The freshly built mcpp.exe died on `--version` with no output at all, right after a green build — the same mask mcpp#230 wore. Passing a real size instead would buy nothing: MSVCRT has no line buffering, it accepts _IOLBF and treats it as _IOFBF. Windows already gets the guarantee from ui::flush(), which every stdout-writing function in this module calls and which `mcpp test`'s result lines now route through. So the platform that cannot do this cheaply is also the one that does not need it — and its 4096-byte block was the smallest of the three to begin with. Line-flushing on Linux re-verified after the change: 421 individual writes for a 30-member workspace test, versus 3 block writes before this series. * fix(test): make --build-timeout opt-in, and put the e2e's `requires` on line 2 Two defects in the previous commits, both caught by asking what the change does to projects that are not this one. --build-timeout defaulted to 900s. That would have turned slow-but-CORRECT builds red: one mcpp-index member builds OpenCV from source and measures 1019s on Linux and 1289s on Windows, so a fifteen-minute ceiling fails it and blames mcpp. The asymmetry with --timeout is real and measured, not stylistic — a test binary running over five minutes is unusual, a cold dependency build running over fifteen is ordinary. How long a build may take is a property of the project, so the project says it; mcpp only has to make saying it possible, and that is what was missing. --timeout keeps its 300s default. 178_test_observability.sh carried `# requires: gcc unix-shell` inside the header block. run_all.sh reads that line with `sed -n '2p'`, so it was inert: the test ran on Windows, where <unistd.h> does not exist and where the deadline runner has no kill-by-handle path, and failed for both reasons. Moved to line 2, and narrowed to `unix-shell` — macOS is the platform this file exists for and it has no GCC. The fixture's sleep is now <chrono>/<thread> so the fixture can never be the reason a run fails. --------- Co-authored-by: sunrisepeak <speakshen@163.com>
1 parent 0547324 commit a969fa4

22 files changed

Lines changed: 1157 additions & 48 deletions
Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
# `mcpp test` 可观测性与有界性 —— 实施计划
2+
3+
配套分析:[`2026-07-31-test-workspace-observability-analysis.md`](2026-07-31-test-workspace-observability-analysis.md)
4+
5+
目标:把 `mcpp test` / `mcpp test --workspace` 从「不报时间、不设期限、还不 flush」变成一个**输出实时、耗时可信、墙钟有界、失败可归因**的操作。
6+
7+
三者互相耦合(分析 §6.3),因此**一个 PR 一起做**
8+
9+
---
10+
11+
## S1 — stdout 实时性(根因:libc 缓冲区差 64 倍)
12+
13+
**问题**:`ui::status/info/finished/plain``execute.cppm` 的测试结果行全是裸 `std::println(...)`,无一处 `fflush`;全仓库无 `setvbuf`。非 TTY 下缓冲区大小由 libc 决定 —— musl 固定 1 KB、Apple libc 取管道 `st_blksize`(64 KB)、MSVCRT 4 KB 且**不支持行缓冲**。同一份输出在三平台的可见时机差 64 倍,进程被 kill 时整段丢失。
14+
15+
**做法(两条腿,因为 setvbuf 在 Windows 上不成立)**:
16+
17+
1. `mcpp::ui::set_line_buffered()`(POSIX 上 `setvbuf(_IOLBF)`),由 `main()` 调用 —— 兜住所有不走 ui 的直接输出。**不能放 `main.cpp`**:非模块 TU 不允许开 global module fragment 引 `<cstdio>`(Clang 直接拒绝,GCC 静默接受)。**Windows 上不调用**:UCRT`size` 合法范围是 `2..INT_MAX`,0 会走 invalid-parameter handler 直接 abort(0xC0000409 → git-bash 报 exit 127),而 MSVCRT 本来就把 `_IOLBF``_IOFBF`,靠 `ui::flush()` 即可。
18+
2. `mcpp::ui` 新增 `flush()`,并在 **每个写 stdout 的 ui 函数**末尾调用(`status` / `info` / `finished` / `plain` / `diagnostic` 的 stdout 分支)。这条在 Windows 上也确定有效,不依赖 `_IOLBF` 语义。
19+
3. `execute.cppm``mcpp test` 的裸 `std::println` 结果行(`... ok` / `FAIL (...)`)改走 `ui::plain`,从而继承 flush。
20+
21+
**验收**:e2e 断言 —— `mcpp test --workspace` 的 stdout 重定向到管道时,**逐行到达**(在扇出中途读到第一个成员的 `test result`,而不是等进程退出)。
22+
23+
---
24+
25+
## S2 — `--timeout` 有界化
26+
27+
**问题**:`TestOptions::timeoutSecs = 0`(不限)是默认值,`mcpp test` 因此不是有界操作。
28+
29+
**做法**:默认改 **300 秒**;`--timeout 0` 显式表示不限。help / `docs/` 同步。
30+
31+
**验收**:单测 + e2e(一个 `sleep` 测试在 `--timeout 1` 下报 `FAIL (timeout after 1s)` 且扇出继续)。
32+
33+
---
34+
35+
## S3 — `--build-timeout`(唯一能兜住链接卡死的闸)
36+
37+
**问题**:`--timeout` 只包住测试进程的**运行**。三处 `backend->build()`(`execute.cppm:1056` Phase A / `:1103` bulk / `:1126` per-test)全无期限。macOS 上 `modules/jsc` 卡在 14 次可执行链接上,`--timeout` 设多少都无效。
38+
39+
**做法**:
40+
- `BuildOptions``buildTimeoutSecs`(0 = 不限,**默认 0 —— 见下**)。
41+
- `ninja_backend``capture_exec` 换成 `capture_exec_deadline`,超时返回 `BuildError{"build timed out after Ns", ...}`
42+
- `run_tests` 三处 build 各自独立计时;超时报成**该成员的构建失败**,扇出继续下一个成员。
43+
- **平台限制如实写明**:`capture_exec_deadline` 在 Windows 上忽略 deadline(`process.cppm:96-99`),因此 `--build-timeout` 目前是 POSIX-only。文档标注,不假装跨平台。
44+
45+
**默认为什么是关的**(与 `--timeout` 不对称,实测而非风格):单个测试跑过 5 分钟不寻常,冷依赖构建跑过 15 分钟很平常 —— mcpp-index 有成员要从源码建 OpenCV,linux 1019s / windows 1289s。默认上限会把「慢但正确」的构建判红。构建能跑多久是工程的性质,由工程来说。
46+
47+
**验收**:e2e —— 一个故意慢的编译边在 `--build-timeout 1` 下被判超时且信息里带成员名。
48+
49+
---
50+
51+
## S4 — 耗时数字可信
52+
53+
**问题 A**:`auto t0``execute.cppm:1107`,即 Phase A + bulk build **之后**才起表,`finished in` 只覆盖 per-test 循环。实测 `modules/jsc` 打印 `6.53s`、真实 `93.5s`,**误差 14.3×**
54+
55+
**问题 B**:per-test 耗时已在 `TestResult::durationMs` 里,但**只发给 JSON**,human 模式的 `t1 ... ok` 不带时间。
56+
57+
**做法**:
58+
- `t0` 移到 Phase A 之前;分别累计 `buildMs`(Phase A + bulk + per-test build)与 `runMs`
59+
- 汇总行:`test result ok. 14 passed; 0 failed; finished in 93.5s (build 87.0s + run 6.5s)`
60+
- per-test human 行带时间:`t1 ... ok (0.31s)` / `t1 ... FAIL (exit 1, 2.40s)`
61+
62+
---
63+
64+
## S5 — 扇出层可观测性
65+
66+
**问题**:97 个成员串行,过程中唯一线索是 `Workspace testing member 'X'`。无 `M/N`、无 per-member 耗时、无累计耗时、无 workspace 级汇总。
67+
68+
**做法**:
69+
- `run_tests` 返回结构化结果(新增 `TestRunSummary{passed, failed, elapsed, buildMs, runMs}`),而不是只回 `int`
70+
- 扇出打:
71+
```
72+
Workspace member 'modules/jsc' (23/97) ok — 14 passed in 93.5s
73+
workspace result ok. 97 members; 412 passed; 0 failed; finished in 355.2s
74+
slowest: modules/jsc 93.5s, modules/install 32.2s, modules/http_types 24.1s
75+
```
76+
- 失败时同样带耗时与 `M/N`
77+
78+
---
79+
80+
## S6 — `--workspace-timeout`
81+
82+
整条扇出的累计墙钟上限(默认 0 = 不限,由 CI 的 `timeout-minutes` 兜底)。超时后**停止扇出**,如实汇总已完成成员、列出未跑成员,退出码非零 —— 而不是被外部 SIGKILL 掉、连汇总都拿不到。
83+
84+
---
85+
86+
## S7 — JSON 输出契约(分析 §4)
87+
88+
1. **表头不再污染 stdout**:`--message-format json` 时,扇出层在调用 `run_tests` **之前**`set_quiet(true)`(现在是第一个成员漏出去、第二个起被静音)。
89+
2. **测试名带成员**:每条 test 记录加 `"member"` 字段。
90+
3. **workspace 级 summary**:`{"workspace_summary":{"members":N,"passed":P,"failed":F,"elapsed_ms":E}}`
91+
92+
---
93+
94+
## S8 — macOS `runtime_library_path_key() == ""` 的静默差异
95+
96+
`platform/env.cppm:163` 在 macOS 返回空串(理由正确:`DYLD_LIBRARY_PATH` 会波及 ninja 启动的每个可执行文件)。后果是依赖 `[runtime] library_dirs` 的测试在 Linux/Windows 过、macOS 以 dyld 错误失败,且**零诊断**
97+
98+
**做法**:`run_tests` 在 macOS 上若 `plan.runtimeLibraryDirs` 非空而注入键为空,发一条 `diag::warning`,点名这条平台差异与 rpath 兜底。
99+
100+
---
101+
102+
## 落地顺序
103+
104+
S1 → S2 → S4 → S5 → S7 → S3 → S6 → S8,每步自带测试。
105+
106+
版本:`2026.8.1.1`(`2026.7.31.1` 已发布)。真源 `src/toolchain/fingerprint.cppm::MCPP_VERSION` + `mcpp.toml`,由 `.github/tools/check_version_pins.sh` 机器校验。

0 commit comments

Comments
 (0)