Fix: gate disabled host spans before formatting - #1875
Conversation
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (16)
Included review availability: Your plan includes up to 1 review per rolling hour; 0 remain after this review. 📝 WalkthroughWalkthroughHost tracing now checks live runtime and logging thresholds before collecting metadata or emitting spans. Native and Python APIs expose activation state. Scheduler instrumentation and logging tests cover enabled, disabled, and unbound states. ChangesHost-span gating
Estimated code review effort: 3 (Moderate) | ~25 minutes Merge Risk: ⚪ Minimal · up to The change gates disabled host spans before formatting and keeps unbound logger instances silent; no actionable merge-blocking risk remains after normal checks and review. Sequence Diagram(s)sequenceDiagram
participant PythonWorker
participant TaskInterface
participant HostTrace
participant Scheduler
participant HostLogger
PythonWorker->>TaskInterface: query _host_spans_active()
TaskInterface->>HostTrace: call enabled()
HostTrace-->>TaskInterface: return runtime state
TaskInterface-->>PythonWorker: return combined activation state
Scheduler->>HostTrace: check enabled()
HostTrace-->>Scheduler: return enabled or disabled
Scheduler->>HostLogger: emit span when enabled
HostLogger-->>Scheduler: suppress work when TIMING is disabled
Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
1063ee5 to
2d9ccfd
Compare
ChaoWao
left a comment
ChaoWao
left a comment
There was a problem hiding this comment.
审了 eeac80d6...2d9ccfde（16 文件 +273/−53，单 commit，就在 main 顶端）。按 #1792 item 3 / item 7 的原文对，不按 PR 描述对。
结论：gate 的机制是对的，覆盖是完整的，我逐个数过 7 个发射点没有漏的。有一条需要处理的行为回归（见 host_log.cpp 的 inline），加一条缺测量。
gate 的四层，以及为什么两层都必要
unified_log_host_span_enabled() 成为 C ABI 的一等查询 → host_trace::enabled() inline 包装 → 六个 C++ 发射点在构造属性之前查询 → log_host_span 在 validate/encode 之前再查一次。
最后那次 recheck 值得单独说：它覆盖的是直接走 C ABI 的调用方 —— pypto 就是这样进来的，它永远看不到 host_span_scope.h 里的 inline gate。只做调用点会把整个外部消费者漏掉。这一层不是冗余。
发射点覆盖（我逐个核过，7/7）：orchestrator.cpp:377,737 · worker_manager.cpp:472,662,745,1013 · worker.py:11054。SpanScope 改 std::optional + emplace 是条件构造的唯一办法，terminal_ns 用 0 做哨兵也安全 —— 它唯一的读者就是 release_run 里那个 trace，而且那里同时守了 terminal_ns != 0。
还有一处微妙但正确的：_set_host_span_level_prefix 在 Worker.init 里不受这个 gate 约束（worker.py:7800）。所以阈值中途从 NUL 抬到 TIMING 时前缀早已 bind，span 名字仍带正确的层级词。commit message 第三条 bullet 说的就是这个，判断对。
一条 Should-fix：全部理由是一个测量值，却没有测量
item 3 是因为一个数字才从优化升级为必需的：~3.34 µs/record，其中只有约一半能靠降级收回，剩下的是 gate 之前的 encode。这个 PR 把 encode 也纳入 gate，等于主张剩下那一半现在也能收回 —— 但没有任何 before/after 数字。
机制我读过是对的，但"3.34 µs 现在全部可回收"这句话本身还没有证据。一次 a2a3sim 在 TIMING vs WARN 下的对比就够，补进 PR body 即可。
做得对的，值得点名
test_host_log_unbound单独建可执行文件，CMake 注释也写明了原因：singleton 是一次性 bindable 的，test_host_log_off一 bind 就再也测不到 unbound 状态。这是唯一正确的做法，而且理由留在了代码里。- Python 测试用阴性对照而不是输出断言 —— 把
time.monotonic_ns和_emit_host_span都 patch 成抛异常，证明的是"没干活"而不只是"没输出"。同一个测试还验了 STRACE-off build 不会去查 runtime gate（短路顺序对）。 test_stubs.cpp补了 stub，符合本仓 cpput 的拓扑要求 —— 新extern "C"符号不补 stub 会挂掉一批 ut target。- 文档三处都准确。 我把阈值语义逐条核过：
DEBUG/INFO/TIMING→ 开，WARN/ERROR/NUL→ 关，新测试的表格、is_enabled的实现、文档措辞三者一致。docs/dfx/host-trace.md里 "Device logging still uses the initialization-time policy" 尤其值得保留 —— 它对应 #1792 底部记的那个未修缺陷（onboard AICPU 只拿到一次性的InitArgs.log_level快照），把"log level 现在是活的"正确地限定在了 host 模块范围内。
一条排序上的事实，不是缺陷
#1792 写过"item 3 应该在 #1793 改名之前落地"，但 #1793 先落了（#1877/#1880）。实际代价为零：改名没有增加发射点，而 host_span_name() 的调用现在落在 gate 内侧，关掉时连名字解析都省了 —— 等于额外收益。那条排序建议可以在 issue 里划掉。
|
补充 item 3 的性能验证。 对比环境
微基准：单个 disabled host span 的调用开销这是一个针对改动点的原生 C++ 测试，不运行完整模型。测试程序直接使用各自版本的生产 程序以 结果：
端到端：真实 L3
|
ChaoWao
left a comment
ChaoWao
left a comment
There was a problem hiding this comment.
再审了一轮 93a0fde0...913e33f0，这次拿 .docs/ 里记的需求做对照，不只看 PR 自述。
结论：机制正确、覆盖完整，上轮四条里两条已修。合入前只有一件硬性的事 —— rebase。
上轮四条的处置，我逐个核实过
| 上轮提的 | 处置 | |
|---|---|---|
| ① | Must-fix query_device_hal 会永久静音 |
✅ 修得正好 |
| ② | 全部理由是一个测量值，却没有测量 | 未补 |
| ③ | enabled() 在帧循环内 |
未改（thread 仍 open，是对的） |
| ④ | 测试留下 NUL 阈值 | ✅ 已修 |
① 值得单独说一句好在哪：main 开头一行 seed，注释写的是 "This executable owns its logger state; no loader binds it." —— 陈述的是 owner 语义这个当前事实，不是"因为 review 说了所以加"。而且 PR body 那条 bullet 写的是 "Seed standalone logger owners"（复数、类别），说明理解的是"永不 bind 的 owner"这一类，而不只是那一个文件。这正是我希望的修法。
一件阻塞项：base 落后 main 17 个 commit
merge-base 是 93a0fde0（#1869），而那 17 个 commit 里包含两轮词汇改名：#1877（l3.*/simpler_run* → 按层级命名）、#1880（L4+ 按网络跳数）、#1886（ext. 保留命名空间 + legacy_spans → invocation_spans）、#1893（L3 的层级词 host → node）。
所以这个 diff 里的 span 名全是旧词汇：
orchestrator.cpp/worker_manager.cpp里的HostSpan::用法本身没问题（名字是运行时拼的），但test_scheduler.cpp的 9 处断言是host.dispatch/host.complete等字面量 → main 上现在是node.*docs/dfx/host-trace.md的改动基于<level>=host(L3) 那一版
好消息是这些会冲突而不是静默错（#1893 改的是同一批行），所以 rebase 时会响亮地告诉你。但 rebase 完要重跑 ctest，因为 test_scheduler.cpp 断言的正是那些 span 名。
三条来自 .docs/ 对照的发现
1. .docs 要的是 enabled(level)，实现给的是 enabled() —— 见 inline。
2. item 7 在 .docs/ 里没有需求条目。 我 grep 了 trace-and-log-requirements.md 和 log-design.md：unbound / pre-bind 默认这件事只有一处间接提及（作为另一条的症状）。也就是说 item 7 是 #1845 落地之后才出现的新问题，.docs 的六条 statement 里没有它的位置。这不是这个 PR 的问题，是 .docs 该补的一行 —— 记在这里只是因为它解释了为什么 item 7 的设计依据比 item 3 薄：它没有一份写在前面的需求可以对。
3. .docs/log-design.md 的 statement 4 预判了 item 7 的来源。 它写的是：
The only thing that must be shared is the state (threshold plus a drop counter): pass a pointer to it when we load each module
item 7 正是这个设计的直接后果 —— 一旦 state 按指针共享，"绑定之前用什么"就成了必须回答的问题，而 statement 4 没有回答它。所以 item 7 不是独立缺陷，是 item 4 的未决尾巴。这条因果值得在某处留下，否则下一个人会以为它是偶发的。
还剩的两条 nit
② 补一次 a2a3sim 在 TIMING vs WARN 下的对比就够。item 3 是因为一个数字（~3.34 µs/record，其中约一半在 gate 之前）才从优化升级为必需的；这个 PR 把 encode 也纳入 gate，等于主张剩下那一半现在也能收回 —— 值得有个数字支撑，而不是只有机制。
③ enabled() 提到循环外，和 submit_dispatch / finish_progress_dispatch 已有的"取一次复用"形状保持一致。
两条都不阻塞。rebase 之后我可以再跑一遍确认。
|
更正我上一条 review 里的一句判断 —— 我说错了，而且方向是低估。 我写的是"这些会冲突而不是静默错，所以是响亮的"。核实后不成立：GitHub 报 真实后果比冲突和"测试红"都糟 —— 是假绿： // 913e33f0, test_scheduler.cpp:1258-1259
EXPECT_FALSE(captured_host_span("host.dispatch"));
EXPECT_FALSE(captured_host_span("host.complete"));
于是 严重性排序，我上一条把它放在了最轻的一档：
让它静默的是 建议的修法：不要只改名字rebase 后把 // 关掉 gate 后不该有任何捕获，无论叫什么
EXPECT_TRUE(captured_host_span_names.empty());（ 这样它比原来更强：原来只排除两个特定名字，新形式排除全部；而且任何改名都不能让它假绿。 附带一点#1886 加的梯子钉子（ |
) Reviewing #1875 turned up how a rename can go silently wrong. That PR adds EXPECT_FALSE(captured_host_span("host.dispatch")); on a base that predates #1893, where the word became `node`. Rebasing produces no conflict — the line is new, not edited — so the assertion looks for a name nothing emits, `captured_host_span` answers false, and `EXPECT_FALSE(false)` **passes**. The test that exists to prove a disabled gate emits nothing would then pass whether the gate works or not. Ranked by when you find out, that is the worst of the three outcomes a rename can have: a conflict is immediate, a red test is one CI run, and a vacuously-true assertion is never. What makes it silent is the negated form — the same staleness under `EXPECT_TRUE` merely goes red. Two changes, and the first is not a new guard but the removal of what made the guard necessary. **The names come from the table the emitter uses.** Eight literals in `test_scheduler.cpp` are now `host_span_name(HostSpan::Dispatch)` and friends. These tests assert that a decision point emitted at all; the name is not their subject, so writing it out was a second copy of it. Taking it from the single source means a rename cannot leave them behind — verified by renaming the level word to `network9` and re-running: the suite stays green because the assertions follow. Under the old literals the same rename would have reddened the `EXPECT_TRUE` ones and silently passed an `EXPECT_FALSE` one. **The C++ pre-bind default is pinned to the ladder.** `host_span_names.h`'s `level_word()` defaults to `"node"`, which was a third hand-written copy of the L3 word: `WorkerLevel` is the source of truth, `strace_timing.py`'s `_NODE_WORDS` is pinned to it by its own test, and this one was pinned to nothing. A level renamed in Python would leave C++ emitting the old word for every span before a Worker binds the prefix, with no test noticing. The pin reads that default through the existing binding rather than adding a symbol: `set_level_prefix("")` returns early without binding, while the binding still reports what is in effect. It runs in a child process because the prefix freezes on first bind, so a Worker constructed anywhere in this process would leave the *bound* word behind instead of the default. `test_graph_failure_still_emits_graph_build_span` also spelled out `node.graph_build`; it now builds the expected name from the worker's own `_host_span_prefix`, which is the contract that assertion is about. Verification: - `pytest tests/ut/py` — 1657 passed, 0 failed. - `ctest -LE requires_hardware` — 107/107. - Negative control for the pin: setting the C++ default back to `"host"` fails `test_the_cpp_pre_bind_level_word_is_the_ladder_word_for_l3` and nothing else. - Negative control for the double-write removal: renaming the level word to `network9` keeps `test_scheduler` green, where a literal would have gone red or, worse, vacuously true. Not every literal span name is a double-write, and the distinction is which side of the test it sits on. A literal that **constructs input** — the `SimplerHostSpan` fed to the logger in `test_host_log_off.cpp`, the fake log lines in `test_strace_timing.py` — is right to be written out: the test owns its input, and it is exercising encoding or parsing over an arbitrary name. A literal that **asserts the implementation emitted a particular name** is the second copy, and that is the class both changes above remove. The eight in `test_scheduler.cpp` were the only ones of that kind. What this does not cover, stated because "renames are guarded now" would be too broad a claim: the pin ties the C++ *default* word to the ladder, not every place a name could be spelled out. `git grep -n '"\(node\|network[123]\)\.'` before landing a rename, and judge each hit by the input-versus-assertion test above.
- Query live TIMING visibility before clocks, metadata, and attribute work - Keep bindable loggers silent until process-state binding - Seed standalone logger owners before they emit diagnostics - Preserve level-resolved host-scheduler names across runtime gates and docs - Cover threshold changes, unbound startup, and disabled scheduler trace work Addresses items 3 and 7 of hw-native-sys#1792.
2 participants
Addresses items 3 and 7 of #1792.