buildcrit

Causal profiling for Ninja builds: which edge, if it were faster, would shorten the wall-clock time of the whole build.

The problem

When a Ninja build takes ten minutes at -j16, the obvious question is which command to optimise. Log viewers such as ninjatracing sort commands by duration, and critical-path analysis finds the longest dependency chain. Neither answers the question. The longest command may sit in a busy period where other work would take its slot anyway. An edge with lots of slack on paper can still shorten the build, because finishing it early frees a slot during contention. And Ninja's greedy scheduler is subject to Graham's anomalies, so making one command faster can make the whole build slower. buildcrit measures the effect directly. It replays the build in a model of Ninja's scheduler and re-runs that model with each edge sped up.

How it works

Input is a .ninja_log from one full build plus the output of ninja -t graph.

1. Parse and join. src/dot.rs parses the subset of Graphviz that ninja -t graph emits. File nodes, ellipse edge nodes, simple arrows for one-in/one-out edges, and dotted arrows for order-only inputs are accepted. Anything else is rejected with a line number. src/ninja_log.rs parses log v5+, where the last line per output wins. A drop in end times marks the start of a new build. src/dag.rs turns the file graph into an edge DAG (A → B when B consumes a file A produces), stored in compressed sparse row form with a cached topological order.

2. Infer parallelism. The -j of the logged build is the maximum overlap of the logged [start, end) intervals, computed by a sweep over sorted endpoints.

3. Replay. src/sim.rs is a discrete-event simulation of a greedy scheduler: j slots, a binary-heap ready queue, and a heap of running commands ordered by finish time. A slot never idles while work is ready. Phony and zero-duration edges complete instantly and never take a slot. The ready-queue key is each edge's observed start time. With that key, replaying the logged durations reproduces every logged start time for any greedy schedule with the same slot count. tests/sim_properties.rs checks this against schedules produced from random hidden priorities.

4. Calibrate. A log records only command time. Ninja also spends time between commands (spawning, reading depfiles, writing the log) while holding the slot, so a bare replay finishes early. calibrate looks for the per-command overhead that makes the replay's makespan match the log. It uses an exponential search, then bisection. Greedy scheduling is not monotone, so it keeps the best value it saw rather than trusting the bisection's endpoint. The overhead is added to slot occupancy but is never sped up.

5. Virtual speedup, Coz-style. For each edge e, shorten only e by the speedup fraction (default 30%), re-simulate, and record baseline makespan − new makespan. Negative values are scheduling anomalies and are reported separately. Re-simulations run in parallel with scoped threads, one reusable simulator per thread.

6. Pruning with proven bounds. Re-simulating every edge costs O(E) simulations of O(E log E) each. src/whatif.rs also computes an upper bound on every edge's saving, valid under the greedy scheduler (anomalies included). Nothing changes before the first moment τ that e behaves differently, so the new makespan is at least the maximum of:

   • the longest path, minus the reduction if e has zero slack;
   • for edges started before τ, the baseline finish plus the longest tail; for edges not yet started, τ + duration + tail;
   • an energy bound: the work left after τ that must fit into [τ, M′ − φ] at j units per unit of time, evaluated over a grid of φ values with one sweep per φ.

   The pruned search re-simulates edges in order of a cheap estimate. That estimate is the reduction minus slack, or reduction / j when slots are contended. The search stops when no skipped edge's bound can reach the current ranking. The result is then certified equal to the exhaustive ranking. If the budget (--budget, default 200) runs out first, the report says so and prints the largest saving a skipped edge could still have.

Worked example

examples/codegen is a 4 s code generator that produces gen.h, which two compiles consume (1 s and 2 s):

gen.h (0–4 s) ──► a.o (4–5 s)
              └─► b.o (4–6 s)          makespan 6 s at -j2

$ buildcrit report --log examples/codegen/ninja_log --graph examples/codegen/graph.dot
graph      3 edges: 3 ran a command, 0 phony, 0 with no log entry
log        v5: makespan 6.00 s at an observed parallelism of 2
replay     -j2 with 0 ms overhead per command: 6.00 s (error 0 ms)
model      -j2: makespan 6.00 s, longest path 6.00 s, total work 7.00 s
what-if    each edge alone made 30% faster

rank  saving  of build  command  sped up  slack  rule  output
   1  1.20 s    20.00%   4.00 s   2.80 s   0 ms  gen   gen.h
   2  600 ms    10.00%   2.00 s   1.40 s   0 ms  cc    b.o

Pruned: re-simulated 2 of 3 candidate edges. Certified: the proven bounds show no skipped edge belongs in this ranking.
Anomalies: none among the re-simulated edges.

Making gen.h 30% faster moves everything after it forward by 1.2 s. b.o saves its full 600 ms because that is less than the 1 s gap to a.o. a.o is absent: it has 1 s of slack, so speeding it up saves nothing. Its proven bound was 0, so it was never re-simulated.

Install and usage

Requires Rust 1.75 or later. The crate has no dependencies. From a checkout of this repository:

cargo install --path .

This installs buildcrit and buildcrit-bench into ~/.cargo/bin. cargo run --release --bin buildcrit -- <args> works without installing.

On a real project, profile one clean build:

cd your-build-dir
ninja -t clean && ninja -j16
ninja -t graph > graph.dot
buildcrit report --log .ninja_log --graph graph.dot --top 20

Options:

buildcrit report --log <.ninja_log> --graph <graph.dot> [options]
    -j, --jobs <n>        slots to analyse at (default: parallelism observed in the log)
    --speedup <s>         fraction each edge is made faster, 0..1 (default: 0.3)
    --top <n>             rows in the ranking (default: 20)
    --budget <k|all>      max re-simulations when pruning (default: 200)
    --exhaustive          re-simulate every edge instead of pruning
    --overhead-ms <ms>    skip calibration and use this per-command overhead
    --threads <n>         worker threads (default: all cores)
    --format <table|json> output format (default: table)

-j can differ from the logged parallelism, which answers "what should I speed up if CI runs at -j8?".

If you have no Ninja build to hand, buildcrit gen writes a synthetic one: a layered random DAG with Pareto-distributed durations, simulated at -j with hidden per-command latency that the log does not record.

$ buildcrit gen --out out/demo --edges 5000 --jobs 16 --latency-ms 8 --seed 7
wrote out/demo/.ninja_log (5244 lines) and out/demo/graph.dot (5001 edges, 7594 arcs)
simulated build: -j16, makespan 408.6 s, total work 2238.6 s

$ buildcrit report --log out/demo/.ninja_log --graph out/demo/graph.dot --top 10 --budget all
graph      5001 edges: 5000 ran a command, 1 phony, 0 with no log entry
log        v5: makespan 408.6 s at an observed parallelism of 16
replay     -j16 with 8 ms overhead per command: 408.6 s (error 0 ms)
model      -j16: makespan 408.6 s, longest path 385.8 s, total work 2278.6 s
what-if    each edge alone made 30% faster

rank   saving  of build  command  sped up    slack  rule  output
   1  113.7 s    27.82%  378.9 s  265.2 s     0 ms  cxx   out/l0/t1021.o
   2   701 ms     0.17%   5.99 s   4.19 s     0 ms  ar    out/l4/t3750.a
   3   206 ms     0.05%  11.26 s   7.88 s  359.0 s  cxx   out/l0/t98.o
   4   196 ms     0.05%   9.17 s   6.42 s  376.6 s  cxx   out/l0/t571.o
   5   151 ms     0.04%   7.18 s   5.02 s  378.6 s  cxx   out/l0/t413.o
   6   140 ms     0.03%   7.03 s   4.92 s  378.0 s  cxx   out/l0/t526.o
   7   136 ms     0.03%   455 ms   319 ms     0 ms  ar    out/l2/t2486.a
   8   119 ms     0.03%   397 ms   278 ms     0 ms  ar    out/l3/t2910.a
   9    96 ms     0.02%   4.60 s   3.22 s  380.7 s  cxx   out/l0/t772.o
  10    94 ms     0.02%   4.50 s   3.15 s  381.3 s  cxx   out/l0/t658.o

Pruned: re-simulated 1919 of 5000 candidate edges. Certified: the proven bounds show no skipped edge belongs in this ranking.
Anomalies: none among the re-simulated edges.

Calibration recovered the hidden 8 ms latency exactly. Ranks 3–6 and 9–10 have six minutes of slack each. Critical-path analysis would call them irrelevant, but they shorten the build because they free a slot while all 16 are busy. Rank 2 is a 6 s archive step on the critical path, and it matters more than compiles that take twice as long. With --exhaustive, the same build gives the same ten rows. It also finds five edges whose 30% speedup makes the build 7–26 ms slower.

With the default --budget 200, this report takes under 0.3 s wall-clock including process startup, against 0.5 s for --exhaustive. It gives the same top 10, but it reports itself as not certified, because a skipped edge could in principle save up to 22.76 s.

--format json emits the same data (graph and log statistics, calibration, search mode and certification, ranking, anomalies, warnings) for scripts.

Results

The benchmark generates a synthetic build and times the pruned search against re-simulating every edge. It then checks that both give the same top-20 ranking. Reproduce with:

cargo run --release --bin buildcrit-bench

50,000 edges, 8 layers, -j32, 30% speedup, budget K=200, top 20, 8 worker threads. Measured on an Apple Silicon (arm64) Mac under macOS 26, release build:

seed	makespan	parse + join	pruned (K=200)	exhaustive	speedup	re-sims pruned / exhaustive	same top-20	certified
1	970.3 s	0.205 s	0.161 s	27.156 s	169x	200 / 50000	yes	no
2	716.5 s	0.202 s	0.166 s	29.811 s	180x	200 / 50000	yes	no
3	663.8 s	0.193 s	0.162 s	30.192 s	186x	200 / 50000	yes	no

Geometric mean speedup is 178x, and the top-20 rankings are identical on all three seeds. At this size and budget the search is not certified. The ranking matched exhaustive re-simulation, but the bounds were not tight enough to prove it without it. The time for a certified result sits between the two columns and depends on the build (1919 of 5000 re-simulations for the demo above). Other sizes: --edges, --jobs, --budget, --top, --speedup, --threads, --seeds 1,2,3.

Correctness claims are covered by the test suite (cargo test):

• One slot gives a makespan equal to the sum of durations. Unlimited slots give the longest path, checked against an independent memoised DP. Every simulated schedule respects dependencies and never runs more than j commands at once.
• With unlimited cores, the saving for every edge on 150 random small DAGs equals brute-force enumeration of all source-to-sink paths.
• Graham's 1966 nine-task instance reproduces all three classic anomalies, and the what-if analysis reports the speedup-induced one as an anomaly.
• The saving bound holds for every edge on 120 random DAGs × 3 speedups × 7 slot counts (more than 50,000 checks), and more than 10% of the bounds are tight.
• Pruning with an unlimited budget is certified and equal to exhaustive re-simulation on 120 random DAGs × 2 speedups × 7 slot counts × 3 ranking lengths, while doing fewer simulations. With a finite budget, a certified result is exact, and an uncertified result's reported bound holds for every skipped edge.
• Calibration recovers hidden scheduler latencies of 0, 1, 4, 25 and 120 ms exactly.
• The CLI tests cover exit codes and error messages for malformed logs, cyclic graphs, logs from the wrong build directory, and invalid flags.

Design notes

Simulate the scheduler instead of reasoning about paths. Critical-path slack is exact only with unlimited cores. Real builds run at a fixed -j where the bottleneck is often slot contention, not a dependency chain, and a closed-form model of greedy scheduling does not exist. Graham's anomalies are the proof. So the core is a plain event simulation, and every number in the ranking comes from one. The cost is that the naive analysis is quadratic: 50,000 edges take about 30 s on eight threads. The obvious shortcut is to rank by an estimate and re-simulate the top few. That is exactly the kind of thing that silently gives wrong answers, because under finite slots a 1 ms speedup can save 41 ms (a_one_unit_speedup_can_save_far_more_than_one_unit). Instead the pruning uses bounds that are proven for the greedy scheduler, and the report distinguishes "certified" from "budget ran out, a skipped edge could still save X". The trade-off is extra code in upper_bounds and a bound that is loose on large builds. On the 50,000-edge benchmark the default budget is fast and matched the exact answer, but it cannot prove that, and it says so.

Replay with observed start times as priorities, then calibrate overhead. Ninja's own ready-queue order depends on manifest details that a log does not record. Ordering the ready queue by observed start time sidesteps this: it reproduces the logged schedule exactly, for any greedy policy, without knowing which policy produced it. The remaining gap between replay and log is time Ninja holds a slot without running a command. One scalar found by search closes it, and the report prints the residual error. A residual above 5% triggers a warning that the log probably comes from a build with pools, -l, or a different -j.

Limitations

• No pools, no -l load limit. The model has one pool of j slots. Edges in the console pool or in a custom pool with a smaller depth are scheduled as if unrestricted. The calibration warning usually flags this, but the ranking will be wrong for those edges.
• Durations are independent of concurrency. Speeding up one command does not change how long the others take. On a machine where commands contend for memory, disk or cache, real savings will differ.
• One edge at a time. The analysis answers "what if this single edge were faster". It does not search for combinations, and savings of different edges do not add up.
• Ready-queue ties after a change. When a speedup reorders events, newly ready edges are started in the order they started in the original build. Real Ninja may pick a different order, so small savings (a few ms on a multi-minute build) are within the model's noise.
• Needs one clean, full build. Incremental logs mix clocks from several builds. This is detected and warned about, but not corrected. Edges with no log entry are treated as up to date (zero duration).
• Graph from ninja -t graph only. Dependencies Ninja discovers during the build (depfiles, dyndep) do not appear there. That is harmless for ordering in the common case, since Ninja already requires generated headers to be declared, but an undeclared dependency would let the model start an edge too early. Ninja's -t graph DOT output is parsed; -t compdb, -t query and CMake's trace formats are not.
• Not exercised against a live Ninja in CI. The parser tests use a fixture shaped like ninja -t graph output, and the end-to-end tests use generated builds. The CI environment does not install Ninja.
• Integer milliseconds. Speedups round to the nearest millisecond, so the analysis is meaningless for commands shorter than a few ms.

License

MIT. See LICENSE.