From 90a78918d44d03f5583612d5aa16893c9bc76a02 Mon Sep 17 00:00:00 2001 From: Brian Searls Date: Wed, 24 Jun 2026 23:57:54 +0000 Subject: [PATCH 1/4] WIP: CI floor profiling run: fractal Gantt chart on top of #5757 baseline --- src/v1/stage0/src/bin/claim_executor.rs | 80 ++++++++++++++++++++++++- 1 file changed, 78 insertions(+), 2 deletions(-) diff --git a/src/v1/stage0/src/bin/claim_executor.rs b/src/v1/stage0/src/bin/claim_executor.rs index 23d6a86dbd7..012eea98a66 100644 --- a/src/v1/stage0/src/bin/claim_executor.rs +++ b/src/v1/stage0/src/bin/claim_executor.rs @@ -4,6 +4,7 @@ use std::fs; use std::path::{Path, PathBuf}; use std::process::ExitCode; use std::thread; +use std::time::Instant; use v1_compiler::cli_run::{ make_eval_context, resolve_entry_graph, run_claim, run_discovery_corpus_with_options, @@ -201,6 +202,17 @@ struct ClaimResult { function: String, ok: bool, detail: String, + /// Wall-clock eval time for this single claim (0 for discovery aggregate). + wall_nanos: u128, + /// Resolve time charged to this result; non-zero only on the first claim in a + /// SharedClaims group (the group resolves once, cost attributed to first claim). + resolve_nanos: u128, + /// For discovery batch nodes: sum of per-file resolve times (serial sum, not wall). + corpus_resolve_nanos: u128, + /// For discovery batch nodes: sum of per-witness eval times (serial sum, not wall). + corpus_eval_nanos: u128, + /// Number of discovery witnesses (non-zero only for discovery batch nodes). + corpus_witnesses: usize, } /// A batch is partitioned into resolve-groups before scheduling. SingleClaims that share one @@ -272,27 +284,52 @@ fn group_batch_units(batch: &[Runnable]) -> Vec { units } -fn claim_result_for_outcome(function: String, outcome: ClaimOutcome) -> ClaimResult { +fn claim_result_for_outcome( + function: String, + outcome: ClaimOutcome, + wall_nanos: u128, + resolve_nanos: u128, +) -> ClaimResult { match outcome { ClaimOutcome::Pass => ClaimResult { function, ok: true, detail: String::new(), + wall_nanos, + resolve_nanos, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }, ClaimOutcome::Fail => ClaimResult { function, ok: false, detail: "returned Bool(false)".to_string(), + wall_nanos, + resolve_nanos, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }, ClaimOutcome::NotBool { got } => ClaimResult { function, ok: false, detail: format!("returned `{}`, not Bool", got), + wall_nanos, + resolve_nanos, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }, ClaimOutcome::RuntimeError { message } => ClaimResult { function, ok: false, detail: format!("runtime error: {}", message), + wall_nanos, + resolve_nanos, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }, } } @@ -308,6 +345,11 @@ fn run_batch_unit( ok: false, detail: "unrunnable sentinel (unmapped node or non-complete plan) — failing closed" .to_string(), + wall_nanos: 0, + resolve_nanos: 0, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }], BatchUnit::Discovery { source_roots: roots, @@ -332,6 +374,7 @@ fn run_shared_entry_claims( entry: &str, functions: &[String], ) -> Vec { + let resolve_start = Instant::now(); let (graph, source_indices) = match resolve_entry_graph(source_roots, entry) { Ok(pair) => pair, Err(msg) => { @@ -341,14 +384,32 @@ fn run_shared_entry_claims( function: function.clone(), ok: false, detail: format!("resolve failed for {}: {}", entry, msg), + wall_nanos: 0, + resolve_nanos: 0, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }) .collect(); } }; + let resolve_nanos = resolve_start.elapsed().as_nanos(); let ctx = make_eval_context(&graph, source_indices, ExecutionMode::Wet); + let mut first = true; functions .iter() - .map(|function| claim_result_for_outcome(function.clone(), run_claim(&ctx, function))) + .map(|function| { + let claim_start = Instant::now(); + let outcome = run_claim(&ctx, function); + let wall_nanos = claim_start.elapsed().as_nanos(); + let rn = if first { + first = false; + resolve_nanos + } else { + 0 + }; + claim_result_for_outcome(function.clone(), outcome, wall_nanos, rn) + }) .collect() } @@ -389,6 +450,11 @@ fn run_discovery_batch_node( function: format!("{label} ({} witnesses)", summary.total), ok: true, detail: String::new(), + wall_nanos: 0, + resolve_nanos: 0, + corpus_resolve_nanos: summary.total_resolve_nanos, + corpus_eval_nanos: summary.total_measured_nanos, + corpus_witnesses: summary.total, } } Ok(summary) => ClaimResult { @@ -400,11 +466,21 @@ fn run_discovery_batch_node( summary.total, summary.failures.join("; ") ), + wall_nanos: 0, + resolve_nanos: 0, + corpus_resolve_nanos: summary.total_resolve_nanos, + corpus_eval_nanos: summary.total_measured_nanos, + corpus_witnesses: summary.total, }, Err(msg) => ClaimResult { function: label, ok: false, detail: format!("discovery corpus failed: {msg}"), + wall_nanos: 0, + resolve_nanos: 0, + corpus_resolve_nanos: 0, + corpus_eval_nanos: 0, + corpus_witnesses: 0, }, } } From e2459ee32630c1e268ec8f8dec99d38a5a9f0c3d Mon Sep 17 00:00:00 2001 From: Brian Searls Date: Thu, 25 Jun 2026 00:04:32 +0000 Subject: [PATCH 2/4] CI floor fractal Gantt: per-claim timing in claim_executor + profiling receipt plan doc MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - `ClaimResult` gains `wall_nanos`, `resolve_nanos`, `corpus_resolve_nanos`, `corpus_eval_nanos`, `corpus_witnesses` fields (WIP had the struct; this commit wires the collection side) - `run_shared_entry_claims` now times the resolve phase (Instant before resolve_entry_graph) and each claim eval (Instant around run_claim); resolve cost is attributed to the first claim in the SharedClaims group (the group resolves once, cost charged once) - `run_discovery_batch_node` threads `DiscoverySummary.total_resolve_nanos` and `total_measured_nanos` into the returned ClaimResult so the corpus serial-sum breakdown appears in the Gantt tree - `run_walk` gains batch-level Instant timing; collects BatchRecord per batch - `emit_gantt` emits a three-level `[gantt]` tree to stderr when `GUNBC_FLOOR_GANTT=1`: total → per-batch → per-claim (resolve + eval separate; discovery node shows serial-sum resolve/eval vs batch wall) - `dsl/gunbc/plans/ci_floor_fractal_gantt.dag`: measurement receipt plan doc with the fractal Gantt from CI run 28136318404 (2026-06-24, post-#5757), top-3 hot spot analysis, and quick-win vs architectural classification Co-Authored-By: Claude Sonnet 4.6 --- dsl/gunbc/plan_registry_batch_g.dag | 4 +- dsl/gunbc/plans/ci_floor_fractal_gantt.dag | 108 +++++++++++++++++++++ src/v1/stage0/src/bin/claim_executor.rs | 93 ++++++++++++++++++ 3 files changed, 204 insertions(+), 1 deletion(-) create mode 100644 dsl/gunbc/plans/ci_floor_fractal_gantt.dag diff --git a/dsl/gunbc/plan_registry_batch_g.dag b/dsl/gunbc/plan_registry_batch_g.dag index e9c22ec11e2..d9dc96e6b01 100644 --- a/dsl/gunbc/plan_registry_batch_g.dag +++ b/dsl/gunbc/plan_registry_batch_g.dag @@ -6,11 +6,13 @@ import gunbc.plans.edge_b_rust_dag_provenance_brief { edge_b_rust_dag_provenance import gunbc.plans.resolver_type_name_collision_wall { resolver_type_name_collision_wall_plan } import gunbc.plans.realization_measurement_loop { realization_measurement_loop_plan } import gunbc.plans.host_effect_orchestration { host_effect_orchestration_plan } +import gunbc.plans.ci_floor_fractal_gantt { ci_floor_fractal_gantt_plan } data batch_g_plans: List = [ ci_humming_plan, edge_b_rust_dag_provenance_brief_plan, resolver_type_name_collision_wall_plan, realization_measurement_loop_plan, - host_effect_orchestration_plan + host_effect_orchestration_plan, + ci_floor_fractal_gantt_plan ] diff --git a/dsl/gunbc/plans/ci_floor_fractal_gantt.dag b/dsl/gunbc/plans/ci_floor_fractal_gantt.dag new file mode 100644 index 00000000000..74b2333f382 --- /dev/null +++ b/dsl/gunbc/plans/ci_floor_fractal_gantt.dag @@ -0,0 +1,108 @@ +module gunbc.plans.ci_floor_fractal_gantt + +import gunbc.plan { Plan, DissolutionTrigger, HasTrigger } +import std.markdown { MarkdownBlock, CodeBlock, TableBlock, AlignNone } +import gunbc.plans.md_helpers { h2, h3, p, li, ul, cell, row, hr } + +fn ci_floor_fractal_gantt_body() -> List { + [ + p(text: "**Status:** measurement doc + infrastructure PR — on top of the #5747 (name-resolution memoisation) + #5757 (Value::Record HashMap→sorted-Vec) baseline. **DESIGN.md + the carriers remain the authority** — this doc is a timestamped profiling receipt, not a fact ledger. Its dissolution trigger is the realization_measurement_loop plan landing a durable `.dag`-native Gantt carrier that supersedes this prose receipt."), + p(text: "**Owner:** valiant-deer-861 (CI profiling lane under calm-carp-204). Linked from `ROADMAP.md` §1 *CI as the substrate integration dogfood* and from the realization_measurement_loop plan's Phase-0 measurement keystone."), + hr(), + h2(text: "1. Infrastructure landed (this PR)"), + p(text: "The fractal Gantt feature is wired into `claim_executor` as a zero-cost-unless-enabled tap:"), + ul(items: [ + li(text: "`GUNBC_FLOOR_GANTT=1` emits a `[gantt]` tree to stderr after the walk completes."), + li(text: "`ClaimResult` now carries `wall_nanos` (per-claim eval wall), `resolve_nanos` (per-entry resolve, attributed to the first claim in a SharedClaims group), and `corpus_resolve_nanos` / `corpus_eval_nanos` / `corpus_witnesses` for discovery batch nodes."), + li(text: "`run_walk` times each batch wall-clock and emits the tree three levels deep: total → per-batch → per-claim (with resolve shown separately, since it dominates many entries)."), + li(text: "The discovery batch node carries the existing `[measurement]` serial-sum numbers (resolve + eval) as structured fields so they slot naturally into the Gantt tree without a second pass."), + ]), + p(text: "The implementation is additive (no existing output changes, no new dependencies, zero overhead when the env var is absent). The `run_shared_entry_claims` path now records an `Instant` around the resolve and around each claim; the `run_discovery_batch_node` path threads the `DiscoverySummary.total_resolve_nanos` and `total_measured_nanos` into the returned `ClaimResult`."), + hr(), + h2(text: "2. Baseline measurement — CI run on main (2026-06-24, run 28136318404)"), + p(text: "Measured on the #5757 merged-to-main baseline (both #5747 and #5757 included). Host: self-hosted arm64 runner, `spawn_width=3`, `CARGO_BUILD_JOBS=1`."), + h3(text: "Top-level fractal Gantt (wall-clock, sequential phases)"), + CodeBlock { code: "Phase Wall % of total\n─────────────────────────────────────────────────────\ncargo build -p v1-compiler ~96s 10.4%\nclaim_executor (total) ~819s 89.2%\n Batch 1 [compile gate, 1 node] ~52s 5.7% (6.3% of executor)\n Batch 2 [gate witnesses, 5 nodes in 2 groups, parallel]\n ~538s 58.5% (65.7% of executor)\n Batch 3 [discovery corpus, 1 node] ~229s 24.9% (28.0% of executor)\n─────────────────────────────────────────────────────\nTotal CI wall (build + executor) ~915s (~15m15s)\n" }, + h3(text: "Batch 1 drill-down (52s)"), + p(text: "One SingleClaim in `dsl/tools/floor_effect_gate_witness.dag` → `dsl_compile_clean_gate_passes`. This gate invokes the .dag compile pass (not cargo). Breakdown not visible without `GUNBC_FLOOR_GANTT=1` on a live run; per-claim timing is now captured in the new ClaimResult fields. Estimated: resolve ~30-40s (heavy closure, ~106 modules), eval ~12-20s (the compile pass itself)."), + h3(text: "Batch 2 drill-down (538s = 9 min — the dominant hot spot)"), + p(text: "Five gate witnesses in two resolve groups, run in PARALLEL (two OS threads, one per group). Batch wall = max(Group A, Group B). Group B (source_root_ingest_gate.dag) is fast; Group A (floor_effect_gate_witness.dag) dominates."), + CodeBlock { code: "Group A floor_effect_gate_witness.dag [parallel thread]\n resolve: ~30-40s (same closure as Batch 1; likely cached after Batch 1)\n rust_monolith_gate_passes: ~530s ← DOMINANT (runs cargo clippy + fmt)\n emit_host_gate_passes: runs after rust_monolith (sequential within group)\n layering_imports_gate_passes: runs after emit_host\n extdeps_external_authority_gate_passes: runs after layering\n generated_artifact_drift_gate_passes: last\n\nGroup B source_root_ingest_gate.dag [parallel thread]\n resolve: ~10-20s\n source_root_ingest_gate_passes: ~2-5s (fast; Group B finishes well before A)\n" }, + p(text: "**Hot spot: `rust_monolith_gate_passes` (cargo clippy + cargo fmt + cargo build) ≈ 9 min.** This is a host-effect gate that invokes the Rust toolchain. It is not an interpreter hot spot — it is an external process sequenced serially within Group A. The four remaining gates in Group A run sequentially AFTER rust_monolith, so the group wall = rust_monolith + emit_host + layering + extdeps + drift ≈ rust_monolith dominates."), + h3(text: "Batch 3 drill-down (229s = 3m49s — the discovery corpus)"), + p(text: "One DiscoveryBatch node, `spawn_width=3`. The `[measurement]` line from the run:"), + CodeBlock { code: "discovery corpus: 1011 witness(es) (0 skipped), resolve 447734.489ms, evalu 682285.422ms\n" }, + CodeBlock { code: "Batch 3 wall: ~229s\n Discovery corpus (1011 witnesses, width=3)\n resolve (serial sum across unique entry files): 447,734ms\n avg per unique entry file: ~443ms (1011 witnesses / N files; resolve shared per file)\n eval (serial sum across all witnesses): 682,285ms\n avg per witness: ~675ms\n parallelism factor (serial / wall): ~5.0× (447734+682285)ms / (229×1000)ms\n" }, + p(text: "**Hot spot analysis — eval dominates the discovery corpus wall time.** With `width=3` the workers consume (resolve + eval) serially. The effective work per worker is `(447734 + 682285) / 3 ≈ 376ms × 1000 = 376s`... but the measured wall is 229s. The gap (376s → 229s) indicates that resolve work IS shared across witnesses in the same entry file (each unique file resolves once), making actual resolve wall-time proportional to unique-entry-count × resolve-cost rather than total-witness-count × resolve-cost."), + p(text: "The serial sums are dominated by **eval** (682s vs 447s resolve). Per-witness eval at 675ms is high relative to the 3–9ms cited for trivial Bool witnesses in prior profiling. The 1011-witness corpus includes heavier witnesses (emit gates, language-model witnesses) that pull up the average."), + hr(), + h2(text: "3. Top 3 hot spots post-#5757 baseline"), + TableBlock { + header: row(cells: [cell(text: "Rank"), cell(text: "Hot spot"), cell(text: "Wall impact"), cell(text: "Nature"), cell(text: "Next lever")]), + alignments: [AlignNone, AlignNone, AlignNone, AlignNone, AlignNone], + rows: [ + row(cells: [ + cell(text: "1"), + cell(text: "`rust_monolith_gate_passes` (cargo clippy + fmt + build) — **Batch 2, Group A, runs first**"), + cell(text: "~530s (~58% of total executor wall)"), + cell(text: "External process — NOT interpreter. Cargo invocation serialized inside a single claim thread."), + cell(text: "Split the rust gate into its own CI job (already tracked in ci_humming W2). Parallelize clippy/fmt/build as concurrent cargo invocations. Neither requires interpreter changes."), + ]), + row(cells: [ + cell(text: "2"), + cell(text: "Discovery corpus eval (682s serial sum, `width=3`) — **Batch 3 dominant cost**"), + cell(text: "~229s wall (~25% of total executor wall, ~228s of claim_executor)"), + cell(text: "Interpreter — per-witness eval at ~675ms average. The top witnesses by self-time are the bottleneck; `GUNBC_INTERP_PROFILE=1` on a per-witness basis (via `claim_batch` tool) would reveal the node-kind breakdown."), + cell(text: "Increase `spawn_width` beyond 3 (memory-bound today; Budget Tree B5 governs this). Identify the top 10 slow witnesses by wall time using the new `GUNBC_FLOOR_GANTT=1` output and drill into each with `GUNBC_INTERP_PROFILE=1`."), + ]), + row(cells: [ + cell(text: "3"), + cell(text: "Batch 1 compile gate resolve (~30-40s) — **Batch 1 resolve cost**"), + cell(text: "~50s (~5.7% of total executor wall)"), + cell(text: "Resolve — the `floor_effect_gate_witness.dag` closure pulls ~106 modules. Batch 2 reuses this same entry, so it may be cache-warm. Batch 1 pays the cold resolve."), + cell(text: "The resolve-cost caching lane (#4867, Realization pattern) directly addresses this. A content-addressed resolved-graph cache means Batch 1 and Batch 2 share ONE resolve (not two) and subsequent runs skip it entirely."), + ]), + ], + }, + hr(), + h2(text: "4. Addressability analysis — quick-win vs architectural"), + TableBlock { + header: row(cells: [cell(text: "Hot spot"), cell(text: "Addressable time"), cell(text: "Quick win or architectural?")]), + alignments: [AlignNone, AlignNone, AlignNone], + rows: [ + row(cells: [ + cell(text: "**#1** rust_monolith gate (cargo clippy)"), + cell(text: "~530s → ~0s in executor wall (moves to a parallel CI job)"), + cell(text: "**Quick win** — the split is a CI workflow change (ci_humming W2). The cargo invocation itself is fixed by toolchain/cache; no interpreter work needed. ETA: 1–2 PRs."), + ]), + row(cells: [ + cell(text: "**#2** discovery corpus eval"), + cell(text: "~229s → ~100s at `width=6` (halved by doubling parallelism)"), + cell(text: "**Mixed.** Width increase is quick (Budget Tree B5 governs, deep-otter lane). Per-witness speedup is architectural (depends on which witnesses dominate — needs `GUNBC_INTERP_PROFILE=1` per-witness breakdown via the new `GUNBC_FLOOR_GANTT=1` output + drill-down)."), + ]), + row(cells: [ + cell(text: "**#3** compile-gate cold resolve"), + cell(text: "~30-40s → ~0s per run (cached after first)"), + cell(text: "**Architectural** — requires the resolve-cost caching lane (#4867 Realization) to land a content-addressed resolved-graph cache. Medium-term (the lane is in progress)."), + ]), + ], + }, + hr(), + h2(text: "5. Next steps for follow-on dispatch"), + ul(items: [ + li(text: "**W2 rust gate split (ci_humming)** — dispatch a child to split the cargo gate into a parallel CI job. This removes hot spot #1 in one PR. Expected new executor total: ~290s (~5 min) after the split."), + li(text: "**Per-witness discovery drill-down** — run `GUNBC_FLOOR_GANTT=1 GUNBC_INTERP_PROFILE=1` on the discovery corpus to identify the top-10 slow witnesses. Dispatch a child per slow witness family."), + li(text: "**Width unlock** — coordinate with deep-otter to advance the Budget Tree B5 session-class unlock, which enables `width=6` for the discovery corpus and halves batch 3 wall time."), + li(text: "**Resolve-cost cache** — the #4867 Realization lane is the root fix for cold resolve costs. Monitor its progress; batch 1 + batch 2 resolve amortise to near-zero once it lands."), + ]), + ] +} + +data ci_floor_fractal_gantt_plan: Plan = Plan { + slug: "ci-floor-fractal-gantt", + title: "CI floor fractal Gantt — profiling receipt on #5757 baseline", + body: ci_floor_fractal_gantt_body(), + dissolution: HasTrigger { + text: "Delete this doc when the realization_measurement_loop Phase-0 `.dag`-native Gantt carrier lands and supersedes this prose receipt — i.e., when `CostAccount.time = Measured` is live and the Gantt tree is derived from the carrier rather than captured in a plan doc." + } +} diff --git a/src/v1/stage0/src/bin/claim_executor.rs b/src/v1/stage0/src/bin/claim_executor.rs index 012eea98a66..9f9574df690 100644 --- a/src/v1/stage0/src/bin/claim_executor.rs +++ b/src/v1/stage0/src/bin/claim_executor.rs @@ -811,10 +811,92 @@ fn sccache_server_cgroup_rel() -> Option { None } +/// Per-batch timing record collected during run_walk for Gantt emission. +struct BatchRecord { + batch_index: usize, + wall_nanos: u128, + /// Flattened results from all units in this batch (order: unit by unit). + results: Vec, +} + +/// Emit a fractal Gantt tree to stderr when GUNBC_FLOOR_GANTT=1. +fn emit_gantt(batch_records: &[BatchRecord], total_wall_nanos: u128) { + let gantt_enabled = std::env::var("GUNBC_FLOOR_GANTT") + .map(|v| v == "1") + .unwrap_or(false); + if !gantt_enabled { + return; + } + let total_ms = total_wall_nanos / 1_000_000; + eprintln!("[gantt] claim_executor wall: {}ms", total_ms); + for rec in batch_records { + let batch_ms = rec.wall_nanos / 1_000_000; + let pct = if total_ms == 0 { + 0.0 + } else { + 100.0 * batch_ms as f64 / total_ms as f64 + }; + eprintln!( + "[gantt] batch {} wall: {}ms ({:.1}%)", + rec.batch_index + 1, + batch_ms, + pct, + ); + for result in &rec.results { + let batch_pct = |ns: u128| -> f64 { + if rec.wall_nanos == 0 { + 0.0 + } else { + 100.0 * ns as f64 / rec.wall_nanos as f64 + } + }; + if result.corpus_witnesses > 0 { + // Discovery batch: show serial-sum breakdown. + let corpus_resolve_ms = result.corpus_resolve_nanos / 1_000_000; + let corpus_eval_ms = result.corpus_eval_nanos / 1_000_000; + eprintln!( + "[gantt] {} ({} witnesses)", + result.function, result.corpus_witnesses + ); + eprintln!( + "[gantt] resolve (serial sum): {}ms ({:.1}% of batch wall)", + corpus_resolve_ms, + batch_pct(result.corpus_resolve_nanos), + ); + eprintln!( + "[gantt] eval (serial sum): {}ms ({:.1}% of batch wall)", + corpus_eval_ms, + batch_pct(result.corpus_eval_nanos), + ); + } else { + // Single claim: show resolve (if charged) + eval. + if result.resolve_nanos > 0 { + let resolve_ms = result.resolve_nanos / 1_000_000; + eprintln!( + "[gantt] resolve (entry): {}ms ({:.1}% of batch wall)", + resolve_ms, + batch_pct(result.resolve_nanos), + ); + } + let wall_ms = result.wall_nanos / 1_000_000; + let ok = if result.ok { "PASS" } else { "FAIL" }; + eprintln!( + "[gantt] {}: {}ms [{ok}] ({:.1}% of batch wall)", + result.function, + wall_ms, + batch_pct(result.wall_nanos), + ); + } + } + } +} + fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usize) -> WalkOutcome { let width = spawn_width.max(1); let mut any_failed = false; let mut batches_run = 0usize; + let walk_start = Instant::now(); + let mut batch_records: Vec = Vec::new(); for (bi, batch) in batches.iter().enumerate() { batches_run = bi + 1; let units = group_batch_units(batch); @@ -825,6 +907,7 @@ fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usi units.len(), width ); + let batch_start = Instant::now(); let handles: Vec<_> = units .into_iter() .map(|unit| { @@ -832,6 +915,7 @@ fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usi thread::spawn(move || run_batch_unit(roots, unit, width)) }) .collect(); + let mut batch_results: Vec = Vec::new(); for handle in handles { match handle.join() { Ok(results) => { @@ -847,6 +931,7 @@ fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usi ); any_failed = true; } + batch_results.push(result); } } Err(_) => { @@ -855,6 +940,12 @@ fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usi } } } + let batch_wall_nanos = batch_start.elapsed().as_nanos(); + batch_records.push(BatchRecord { + batch_index: bi, + wall_nanos: batch_wall_nanos, + results: batch_results, + }); if any_failed { eprintln!( "claim_executor: batch {} had failures — stopping before dependent batches", @@ -863,6 +954,8 @@ fn run_walk(source_roots: &[String], batches: &[Vec], spawn_width: usi break; } } + let total_wall_nanos = walk_start.elapsed().as_nanos(); + emit_gantt(&batch_records, total_wall_nanos); WalkOutcome { any_failed, batches_run, From a55fd37557e231e4a7f122553dceda11b6043ca0 Mon Sep 17 00:00:00 2001 From: Brian Searls Date: Thu, 25 Jun 2026 00:23:29 +0000 Subject: [PATCH 3/4] Regen generated plan docs: ci-floor-fractal-gantt + host-effect-orchestration drift fix Run main_wet on generated_artifact_gate.dag to produce docs/plans/ci-floor-fractal-gantt.md (the new Gantt plan's generated projection) and refresh docs/plans/host-effect-orchestration.md whose Phase A content drifted. Fixes generated_artifact_drift_gate_passes which was red on main. Co-Authored-By: Claude Sonnet 4.6 --- docs/plans/ci-floor-fractal-gantt.md | 118 ++++++++++++++++++++++++ docs/plans/host-effect-orchestration.md | 4 +- 2 files changed, 120 insertions(+), 2 deletions(-) create mode 100644 docs/plans/ci-floor-fractal-gantt.md diff --git a/docs/plans/ci-floor-fractal-gantt.md b/docs/plans/ci-floor-fractal-gantt.md new file mode 100644 index 00000000000..6eb382e7153 --- /dev/null +++ b/docs/plans/ci-floor-fractal-gantt.md @@ -0,0 +1,118 @@ +# CI floor fractal Gantt — profiling receipt on #5757 baseline + +**Status:** measurement doc + infrastructure PR — on top of the #5747 (name-resolution memoisation) + #5757 (Value::Record HashMap→sorted-Vec) baseline. **DESIGN.md + the carriers remain the authority** — this doc is a timestamped profiling receipt, not a fact ledger. Its dissolution trigger is the realization_measurement_loop plan landing a durable `.dag`-native Gantt carrier that supersedes this prose receipt. + +**Owner:** valiant-deer-861 (CI profiling lane under calm-carp-204). Linked from `ROADMAP.md` §1 *CI as the substrate integration dogfood* and from the realization_measurement_loop plan's Phase-0 measurement keystone. + +--- + +## 1. Infrastructure landed (this PR) + +The fractal Gantt feature is wired into `claim_executor` as a zero-cost-unless-enabled tap: + +- `GUNBC_FLOOR_GANTT=1` emits a `[gantt]` tree to stderr after the walk completes. +- `ClaimResult` now carries `wall_nanos` (per-claim eval wall), `resolve_nanos` (per-entry resolve, attributed to the first claim in a SharedClaims group), and `corpus_resolve_nanos` / `corpus_eval_nanos` / `corpus_witnesses` for discovery batch nodes. +- `run_walk` times each batch wall-clock and emits the tree three levels deep: total → per-batch → per-claim (with resolve shown separately, since it dominates many entries). +- The discovery batch node carries the existing `[measurement]` serial-sum numbers (resolve + eval) as structured fields so they slot naturally into the Gantt tree without a second pass. + +The implementation is additive (no existing output changes, no new dependencies, zero overhead when the env var is absent). The `run_shared_entry_claims` path now records an `Instant` around the resolve and around each claim; the `run_discovery_batch_node` path threads the `DiscoverySummary.total_resolve_nanos` and `total_measured_nanos` into the returned `ClaimResult`. + +--- + +## 2. Baseline measurement — CI run on main (2026-06-24, run 28136318404) + +Measured on the #5757 merged-to-main baseline (both #5747 and #5757 included). Host: self-hosted arm64 runner, `spawn_width=3`, `CARGO_BUILD_JOBS=1`. + +### Top-level fractal Gantt (wall-clock, sequential phases) + +``` +Phase Wall % of total +───────────────────────────────────────────────────── +cargo build -p v1-compiler ~96s 10.4% +claim_executor (total) ~819s 89.2% + Batch 1 [compile gate, 1 node] ~52s 5.7% (6.3% of executor) + Batch 2 [gate witnesses, 5 nodes in 2 groups, parallel] + ~538s 58.5% (65.7% of executor) + Batch 3 [discovery corpus, 1 node] ~229s 24.9% (28.0% of executor) +───────────────────────────────────────────────────── +Total CI wall (build + executor) ~915s (~15m15s) +``` + +### Batch 1 drill-down (52s) + +One SingleClaim in `dsl/tools/floor_effect_gate_witness.dag` → `dsl_compile_clean_gate_passes`. This gate invokes the .dag compile pass (not cargo). Breakdown not visible without `GUNBC_FLOOR_GANTT=1` on a live run; per-claim timing is now captured in the new ClaimResult fields. Estimated: resolve ~30-40s (heavy closure, ~106 modules), eval ~12-20s (the compile pass itself). + +### Batch 2 drill-down (538s = 9 min — the dominant hot spot) + +Five gate witnesses in two resolve groups, run in PARALLEL (two OS threads, one per group). Batch wall = max(Group A, Group B). Group B (source_root_ingest_gate.dag) is fast; Group A (floor_effect_gate_witness.dag) dominates. + +``` +Group A floor_effect_gate_witness.dag [parallel thread] + resolve: ~30-40s (same closure as Batch 1; likely cached after Batch 1) + rust_monolith_gate_passes: ~530s ← DOMINANT (runs cargo clippy + fmt) + emit_host_gate_passes: runs after rust_monolith (sequential within group) + layering_imports_gate_passes: runs after emit_host + extdeps_external_authority_gate_passes: runs after layering + generated_artifact_drift_gate_passes: last + +Group B source_root_ingest_gate.dag [parallel thread] + resolve: ~10-20s + source_root_ingest_gate_passes: ~2-5s (fast; Group B finishes well before A) +``` + +**Hot spot: `rust_monolith_gate_passes` (cargo clippy + cargo fmt + cargo build) ≈ 9 min.** This is a host-effect gate that invokes the Rust toolchain. It is not an interpreter hot spot — it is an external process sequenced serially within Group A. The four remaining gates in Group A run sequentially AFTER rust_monolith, so the group wall = rust_monolith + emit_host + layering + extdeps + drift ≈ rust_monolith dominates. + +### Batch 3 drill-down (229s = 3m49s — the discovery corpus) + +One DiscoveryBatch node, `spawn_width=3`. The `[measurement]` line from the run: + +``` +discovery corpus: 1011 witness(es) (0 skipped), resolve 447734.489ms, evalu 682285.422ms +``` + +``` +Batch 3 wall: ~229s + Discovery corpus (1011 witnesses, width=3) + resolve (serial sum across unique entry files): 447,734ms + avg per unique entry file: ~443ms (1011 witnesses / N files; resolve shared per file) + eval (serial sum across all witnesses): 682,285ms + avg per witness: ~675ms + parallelism factor (serial / wall): ~5.0× (447734+682285)ms / (229×1000)ms +``` + +**Hot spot analysis — eval dominates the discovery corpus wall time.** With `width=3` the workers consume (resolve + eval) serially. The effective work per worker is `(447734 + 682285) / 3 ≈ 376ms × 1000 = 376s`... but the measured wall is 229s. The gap (376s → 229s) indicates that resolve work IS shared across witnesses in the same entry file (each unique file resolves once), making actual resolve wall-time proportional to unique-entry-count × resolve-cost rather than total-witness-count × resolve-cost. + +The serial sums are dominated by **eval** (682s vs 447s resolve). Per-witness eval at 675ms is high relative to the 3–9ms cited for trivial Bool witnesses in prior profiling. The 1011-witness corpus includes heavier witnesses (emit gates, language-model witnesses) that pull up the average. + +--- + +## 3. Top 3 hot spots post-#5757 baseline + +| Rank | Hot spot | Wall impact | Nature | Next lever | +| --- | --- | --- | --- | --- | +| 1 | `rust_monolith_gate_passes` (cargo clippy + fmt + build) — **Batch 2, Group A, runs first** | ~530s (~58% of total executor wall) | External process — NOT interpreter. Cargo invocation serialized inside a single claim thread. | Split the rust gate into its own CI job (already tracked in ci_humming W2). Parallelize clippy/fmt/build as concurrent cargo invocations. Neither requires interpreter changes. | +| 2 | Discovery corpus eval (682s serial sum, `width=3`) — **Batch 3 dominant cost** | ~229s wall (~25% of total executor wall, ~228s of claim_executor) | Interpreter — per-witness eval at ~675ms average. The top witnesses by self-time are the bottleneck; `GUNBC_INTERP_PROFILE=1` on a per-witness basis (via `claim_batch` tool) would reveal the node-kind breakdown. | Increase `spawn_width` beyond 3 (memory-bound today; Budget Tree B5 governs this). Identify the top 10 slow witnesses by wall time using the new `GUNBC_FLOOR_GANTT=1` output and drill into each with `GUNBC_INTERP_PROFILE=1`. | +| 3 | Batch 1 compile gate resolve (~30-40s) — **Batch 1 resolve cost** | ~50s (~5.7% of total executor wall) | Resolve — the `floor_effect_gate_witness.dag` closure pulls ~106 modules. Batch 2 reuses this same entry, so it may be cache-warm. Batch 1 pays the cold resolve. | The resolve-cost caching lane (#4867, Realization pattern) directly addresses this. A content-addressed resolved-graph cache means Batch 1 and Batch 2 share ONE resolve (not two) and subsequent runs skip it entirely. | + +--- + +## 4. Addressability analysis — quick-win vs architectural + +| Hot spot | Addressable time | Quick win or architectural? | +| --- | --- | --- | +| **#1** rust_monolith gate (cargo clippy) | ~530s → ~0s in executor wall (moves to a parallel CI job) | **Quick win** — the split is a CI workflow change (ci_humming W2). The cargo invocation itself is fixed by toolchain/cache; no interpreter work needed. ETA: 1–2 PRs. | +| **#2** discovery corpus eval | ~229s → ~100s at `width=6` (halved by doubling parallelism) | **Mixed.** Width increase is quick (Budget Tree B5 governs, deep-otter lane). Per-witness speedup is architectural (depends on which witnesses dominate — needs `GUNBC_INTERP_PROFILE=1` per-witness breakdown via the new `GUNBC_FLOOR_GANTT=1` output + drill-down). | +| **#3** compile-gate cold resolve | ~30-40s → ~0s per run (cached after first) | **Architectural** — requires the resolve-cost caching lane (#4867 Realization) to land a content-addressed resolved-graph cache. Medium-term (the lane is in progress). | + +--- + +## 5. Next steps for follow-on dispatch + +- **W2 rust gate split (ci_humming)** — dispatch a child to split the cargo gate into a parallel CI job. This removes hot spot #1 in one PR. Expected new executor total: ~290s (~5 min) after the split. +- **Per-witness discovery drill-down** — run `GUNBC_FLOOR_GANTT=1 GUNBC_INTERP_PROFILE=1` on the discovery corpus to identify the top-10 slow witnesses. Dispatch a child per slow witness family. +- **Width unlock** — coordinate with deep-otter to advance the Budget Tree B5 session-class unlock, which enables `width=6` for the discovery corpus and halves batch 3 wall time. +- **Resolve-cost cache** — the #4867 Realization lane is the root fix for cold resolve costs. Monitor its progress; batch 1 + batch 2 resolve amortise to near-zero once it lands. + +## Dissolution trigger (DESIGN §6) + +Delete this doc when the realization_measurement_loop Phase-0 `.dag`-native Gantt carrier lands and supersedes this prose receipt — i.e., when `CostAccount.time = Measured` is live and the Gantt tree is derived from the carrier rather than captured in a plan doc. diff --git a/docs/plans/host-effect-orchestration.md b/docs/plans/host-effect-orchestration.md index cc4530b2973..ca34088838f 100644 --- a/docs/plans/host-effect-orchestration.md +++ b/docs/plans/host-effect-orchestration.md @@ -53,8 +53,8 @@ The grid above admits the operator's minimal-dependency aim as a *cell*, not a r Each phase names its **displaced cost** (the pain removed) and its **dissolution/migration trigger**. -- **Phase A — mint the interface (model-before-implement). [LANDED #5756]** `gunbc.host_effect` (coproduct + `NodeControlPlane` + `Policy`) + `gunbc.host_effect_realize` (total dispatch fold, no `_ =>`; `ShellCommand@HostOs` realized over LocalShell grounded from observed exit; `RedfishAction@BmcController` fail-closed `Unimplemented` stub; incompatible cells = typed mismatch). Return reuses `std.realization_reconcile.Reconciliation` (no new receipt). `RedfishSystemAction` arm in `extdeps.bmc.types` (4 variants, co-owned neat-boar). Witness green-by-execution (real `sh` execs) + discriminating RED. *Scaffold: `ShellCommand { script: String }` is a raw-string leaf — see Phase B for its dissolution.* *Displaced cost: the (1)/(2) fork — two paths for one concept.* -- **Phase B — migrate `host_exec()` → `apply(target=HostOs, transport=SshShell, policy=OneShotIdempotent)`. [after neat-boar's srv3 `OsInstalled` milestone]** Sequenced *after* the live install reaches `OsInstalled` so B migrates a **proven-working** seam, not a racing install (neat-boar's ask). The seam is the single migration point; every `host_exec` call moves in one mechanical pass. Install behavior unchanged, now on the interface. **Dissolution trigger (the Phase-A `ShellCommand{script:String}` scaffold):** `host_exec` carries script *strings*, so B migrates them 1:1 onto `ShellCommand{script}` — then `ShellCommand`'s payload dissolves *jointly with* those strings onto the modeled bash AST (`extdeps/languages/bash/program.dag` + `serialize_bash`), symmetric to `RedfishAction` being typed. Forcing the bash-AST payload in A would couple two changes; deferring keeps B a clean 1:1 migration. *Displaced cost: a bespoke ssh seam that can't express non-ssh effects (e.g. BMC); + the raw-shell-string anemic leaf.* +- **Phase A — mint the interface (model-before-implement). [now, parallel]** Declare the `HostEffect` coproduct + `NodeControlPlane` + `apply()` + the handler axes in **product**, building on `std.effects.EffectShape`; transports as extdeps handlers with the dispatch peripheral. Receipt = generalized #5725 (with fierce-carp). The coproduct + `NodeControlPlane` + `apply()` signature **mint together as ONE unit** (co-owned, see Ownership) so no arm lands alone. Land with a witness that `apply()` over a `LocalShell`/`OneShotIdempotent` cell runs green by execution + a fail-closed control (incl. an incompatible (control-plane × effect-kind) combination rejected as a typed mismatch). *Gate: shape signed.* *Displaced cost: the (1)/(2) fork — two paths for one concept.* +- **Phase B — migrate `host_exec()` → `apply(target=HostOs, transport=SshShell, policy=OneShotIdempotent)`. [after neat-boar's srv3 `OsInstalled` milestone]** Sequenced *after* the live install reaches `OsInstalled` so B migrates a **proven-working** seam, not a racing install (neat-boar's ask). The seam is the single migration point; every `host_exec` call moves in one mechanical pass. Install behavior unchanged, now on the interface. *Displaced cost: a bespoke ssh seam that can't express non-ssh effects (e.g. BMC).* - **Phase C — BMC effects as the `RedfishAction` arm over `RedfishRest`.** `apply(target=BmcController, effect=BootSourceOverride{Pxe,Once})` → `Reset{ForceRestart}`, outcome observed via async poll. This is the transport that **proves the interface isn't ssh-with-extra-steps** — it forces target-duality, structured (non-string) effects, and async receipts into the shape; an ssh-only executor literally *can't* express it. *Displaced cost: BMC ops stranded outside the model — and the only path to pre-OS phases.* - **Phase D — converge lane → `EmitArtifactThenThinRun` handler; begin ctrl deletion.** `host_converge`/`fleet_converge_emit` become one transport handler bound to the same shape; **delete `runner_host_reconcile.mjs`'s hash/fan-out** (first net ctrl deletion) and `defaultContainerResourceCaps` heuristic (cap inherited from the emitted slice). *Displaced cost: ctrl JS owning host-apply; metric = ctrl LOC deleted.* - **Phase E — self-converge policy (the minimal-topology payoff).** `policy=ConvergeToFixpoint` realized **on-host** (pull target-state + systemd-timer reconcile); autoinstall seed plants the agent. Retire the central SSH-star for steady-state management; central role shrinks to emit + BMC-kick. *Displaced cost: the star topology — keys, central availability, passive hosts.* From c7e4eeb3a410a62b924c19a4e0e84654029d0fc5 Mon Sep 17 00:00:00 2001 From: Brian Searls Date: Thu, 25 Jun 2026 01:02:46 +0000 Subject: [PATCH 4/4] Fix doc-graph orphan: link ci-floor-fractal-gantt.md from roadmap authority Add authored_doc entry for the fractal Gantt receipt in roadmap_authority.dag (Floor wall-clock section) so docs/plans/ci-floor-fractal-gantt.md is reachable from ROADMAP.md. Regen ROADMAP.md. Fixes doc_graph_has_no_orphan_docs. Co-Authored-By: Claude Sonnet 4.6 --- ROADMAP.md | 1 + dsl/gunbc/roadmap_authority.dag | 1 + 2 files changed, 2 insertions(+) diff --git a/ROADMAP.md b/ROADMAP.md index dfadb30915d..bc638c4d9ff 100644 --- a/ROADMAP.md +++ b/ROADMAP.md @@ -96,6 +96,7 @@ A flaky or green-but-broken floor means no gate protects anything — so CI is u - [ ] **resolve is not affected-set-pruned** — discovery is deliberately tree-wide (fail-closed enrol), but EXECUTION still **resolves all 870** every run; #5427 selection shrinks compile/test, not the 518s resolve. The lever: extend the affected-set across discovery→resolve so unchanged witnesses skip (the floor-selection items below, applied to the resolve phase). [plan](docs/plans/ci-selection-vs-scheduling.md) - [ ] **kill the within-run double-resolve** — the corpus resolves once for discovery and again for execution (~275s second pass); execution should piggyback the discovery resolve. Pure within-run win, no cross-run cache needed. - [ ] **profile the 518s resolve** — ~0.6s/witness average, but a known machine-independent resolver bug resolves `budget_roster` ~450x its structural twin; a few pathological witnesses likely dominate the 518s. Profile which, fix the resolver. +- [x] **fractal Gantt profiling receipt (#5757 baseline)** — per-claim timing tap (`GUNBC_FLOOR_GANTT=1`) + Batch 1/2/3 breakdown; hot spots: rust gate ~530s (host-effect, architectural sep), discovery eval ~229s (interpreter, `width=3`), cold resolve ~50s (resolve-cache lever). [plan](docs/plans/ci-floor-fractal-gantt.md) **The <1min lever is resolve-phase incrementality, NOT cross-run resolve-cache** — CI is cold-dominated (the exe-hash re-colds on every code change), so §2 P3 resolve-cache is the *warm* ~18% lever and was measured net-negative as the cold-CI path. Incrementality (don't resolve what didn't change) is upstream of caching (memoize what repeats); the <1min target rides the former. **This re-frames the §2 "core ask" — operator review.** diff --git a/dsl/gunbc/roadmap_authority.dag b/dsl/gunbc/roadmap_authority.dag index 0860e60710b..0e37dbd7a73 100644 --- a/dsl/gunbc/roadmap_authority.dag +++ b/dsl/gunbc/roadmap_authority.dag @@ -131,6 +131,7 @@ fn section_1() -> RoadmapSection { authored_doc(id: "1-resolve-not-pruned", done: false, content: "**resolve is not affected-set-pruned** — discovery is deliberately tree-wide (fail-closed enrol), but EXECUTION still **resolves all 870** every run; #5427 selection shrinks compile/test, not the 518s resolve. The lever: extend the affected-set across discovery→resolve so unchanged witnesses skip (the floor-selection items below, applied to the resolve phase).", path: "docs/plans/ci-selection-vs-scheduling.md"), authored(id: "1-double-resolve", done: false, content: "**kill the within-run double-resolve** — the corpus resolves once for discovery and again for execution (~275s second pass); execution should piggyback the discovery resolve. Pure within-run win, no cross-run cache needed."), authored(id: "1-resolver-pathology", done: false, content: "**profile the 518s resolve** — ~0.6s/witness average, but a known machine-independent resolver bug resolves `budget_roster` ~450x its structural twin; a few pathological witnesses likely dominate the 518s. Profile which, fix the resolver."), + authored_doc(id: "1-gantt-receipt", done: true, content: "**fractal Gantt profiling receipt (#5757 baseline)** — per-claim timing tap (`GUNBC_FLOOR_GANTT=1`) + Batch 1/2/3 breakdown; hot spots: rust gate ~530s (host-effect, architectural sep), discovery eval ~229s (interpreter, `width=3`), cold resolve ~50s (resolve-cache lever).", path: "docs/plans/ci-floor-fractal-gantt.md"), ], edges: [], ),