fold/docs/internal/perf-audit.md
2026-05-27 10:36:57 -04:00

21 KiB
Raw Permalink Blame History

fold performance audit (2026-05-23)

Purpose and scope

fold's --profile output rolls per-detector wall-clock into a flat list. That answered "which detector is slow?" but not "where does the unaccounted time go?" or "what overhead is self-inflicted?".

This audit captures a baseline on a real codebase (curl), surfaces the previously-hidden phases, ranks the self-inflicted overhead by observed cost rather than gut feel, and queues concrete fixes against the data.

In scope:

  • Phase-level breakdown of analyze_ms.
  • Existing cache + shared-state surfaces.
  • Multi-walk redundancy (does the same TU/function get visited multiple times when one pass would do?).
  • Fold-on-fold static findings — does our own code have duplication worth refactoring?

Out of scope:

  • Z3 algorithmic complexity (not ours to optimise).
  • Clang's ASTUnit::create cost per TU (architectural; mitigations listed in the backlog).
  • Worker fanout + IPC mechanics beyond timing them.
  • Detector precision/recall (separate concern; tracked in docs/research/frontier.md and bench/results/).

Methodology

  • Target: curl (../curl-source/curl/build/compile_commands.json), 306 TUs, 2339 functions. Picked because it's the documented bench baseline (bench/run_curl_ab.py) and fits a single-machine session.
  • Detector set: clone,dead,equiv,null-deref — covers the clone hashing phase + the most expensive security detector (null-deref).
  • Mode: --profile forces single-process serial execution (src/cli/scan_router.cpp:244). All wall-clock numbers below are serial; multi-worker reduces wall-clock proportionally for the detector phases but not for the parts that already serialise (call- graph build, cross-TU priming).
  • Tooling: /usr/bin/time -p for wall-clock; --profile-output for JSON breakdown; python3 + jq-equivalents for parsing.
  • Baseline artifact: docs/internal/perf-audit/baseline-instrumented-2026-05-23.json.
  • Fold-on-fold artifact: docs/internal/perf-audit/fold-on-fold-2026-05-23.json (639 findings); triage in docs/internal/perf-audit/fold-on-fold.md.

Existing caches inventory

Six caches were mapped (Phase-1 exploration). Summary:

Cache Scope Key Invalidation Notes
CrossTUCache per-scan, process-global qualified function name → CalleeProperties cleared at shard boundary Primed by a dedicated walk; rebuilt every scan
SummaryStore per-scan, process-global qualified name → SymbolicSummary transitive on dependent change In-memory only; no disk persistence
ExprCache per-TU, process-global z3 expr hash → check_result cleared at TU boundary Aggressive invalidation; solver results don't carry across functions
IncrementalCache per-scan, disk-persisted function (src hash, callee hash) source/callee hash change Opt-in via --incremental; forces --processes=1
ProjectCallGraph per-scan, in-memory def → callees + SCCs rebuilt every scan Not persisted
BufferSizeTracker, HeapModel per-function per-SymbolicEnv end of function Correct lifetime; not a cache problem

Note: subprocess workers don't share any of these — each cold- starts. That's a clang-binding limitation we can mitigate but not eliminate.

Empirical baseline

From docs/internal/perf-audit/baseline-instrumented-2026-05-23.json:

total_wall_ms:                455,756 (7.6 min)
compile_db_load_ms:                 2
fanout_orchestration_ms:            0   (profile mode → serial)
serial_dispatch_ms:           455,682
parse_ms:                           0
analyze_ms:                   455,685
report_ms:                         71

detector wall_ms breakdown:
  null-deref                  297,955  (65.4% of total)
  dead                          8,750  ( 1.9%)
  equiv                         2,240  ( 0.5%)
  clone                           216  ( 0.05%)
  -------------------------------------
  sum                         309,161  (67.8%)

  serial_dispatch_ms - sum    146,521  (32.2%)

Two findings jump out:

  1. null-deref dominates: 65% of total wall. With ~3s of actual Z3 query time (from [solver-profile] z3_time_ms aggregate), the other ~297s is in the encoder / state-merging / walker.
  2. ~32% (146s) was previously unaccounted. New instrumentation localizes it to serial_dispatch_ms minus detector wall — i.e., inside runDetectorsOnShard but outside any detector handler. That bucket contains: clang ASTUnit construction per TU (~1.0s × 306 ≈ 306s of CPU, but clang parses are roughly 0.5s wall each on this hardware → ~150s wall, matches), cross-TU priming (~1 full extra AST walk per TU), call-graph collection, function fingerprinting.

Self-inflicted-overhead findings (ranked by observed cost)

1. clang ASTUnit constructed once per TU, never shared

Observed cost: ~150s of the 455s baseline (33%). Dominant contributor to serial_dispatch_ms - sum(detector.wall_ms).

Where: src/frontend/clang_backend.cpp:144. Each TU spawns a fresh clang::tooling::ClangTool::run(). Worker subprocesses amplify this: each worker re-parses every TU it owns from cold.

Remediation sketch:

  • Short-term: emit precompiled headers (PCH) for project headers used by every TU; clang accepts -include-pch per invocation.
  • Medium-term: persistent worker that holds an LRU of recently- parsed ASTUnits keyed by TU + clang flags hash; new commands reach it over a Unix socket. Requires a daemon model that fold doesn't have today.
  • Long-term: explore clang's ASTReader snapshot format if it becomes usable for our access patterns.

Estimated payoff: 30–50% wall-clock reduction on warm runs. The exact number depends on PCH coverage of fold's clang include graph.

2. null-deref encoder + walker traversal: 5 min CPU per curl scan

Observed cost: ~287s of detector wall, ~99% outside Z3.

Where: src/detect/null_deref.cpp + src/symbolic/encoder.cpp

  • the security walker's path enumeration.

Phase breakdown (final — baseline-hooks-2026-05-23.json):

null-deref wall_ms:       344,644
  walker_ms:              340,329   (98.8% of wall — almost all in walk/walkCFG)
  encode_ms:               24,156   (7.1% of walker — NOT the target)
  hook_ms:                 11,860   (3.5% of walker — NOT the target)
  state_merge_ms:              75   (0.02% of walker — NOT the target)
  walker - the above:     304,238   (89.4% of walker — the actual cost)

Aggregate z3_time_ms across the entire scan: ~33ms (<0.01% of total).

Four wrong hypotheses, four pivots:

  1. Hash-walk fusion (original plan): 0.04% of total.
  2. State-merge optimization: 0.02% of null-deref walker.
  3. Encoder optimization: 7% of null-deref walker.
  4. Hook body optimization: 3.5% of null-deref walker.

The 304s that remains after subtracting all four was originally hypothesised as "per-stmt bookkeeping that fires for every statement." A second-round decomposition (Backlog #2) added four timers — cfg_build_ms, nonnull_precompute_ms, control_walk_ms, stmt_overhead_ms — and revised that hypothesis with measurement.

Final decomposition (curl null-deref baseline):

Phase ms % of walker_ms
control_walk_ms (walkIf + walkSwitch + walkFor + walkWhile + walkDo) 254,102 85.3%
encode_ms 4,614 1.5%
hook_ms 2,808 0.9%
stmt_overhead_ms (snapshot-delta remainder) 287 0.1%
state_merge_ms / cfg_build_ms / nonnull_precompute_ms 0 0%
walker_ms total 297,749 100%

The 89% bucket is recursive control-flow body walks, not per-stmt bookkeeping. Each walkIf clones envs, recursively walks each arm, and merges; walkFor/walkWhile unroll; the recursion re-enters the per-block loop. Most source code lives inside control structures, so most analysis time naturally falls there.

Caveat on double-counting: control_walk_ms covers the full wall of the recursive walks, including the nested encode_ms/hook_ms slices fired inside them. The 254s double-counts ≈7s of inner encode+hook; net ≈247s is the recursive walking machinery itself (env clone, refine ranges, body walk, merge).

A separate hypothesis — "env clones in walkIf dominate control_walk_ms" — was added and refuted by direct measurement: env_clone_ms totals 0 across 770,748 clones (under 1 µs each, since z3::expr refcount bumps and 11 unordered_map shallow copies amortize to nothing).

Remediation candidates for the 89%:

  1. Bound walkForStmt/walkWhileStmt unroll cost — large loops multiply the recursion factor.
  2. Cache refineRangesForCondition / refineOctagonForCondition results across re-entries of the same branch.

Neither will eliminate the bucket. The cost is symbolic execution proportional to (statements × control-nesting depth). Meaningful wall reduction requires changing the semantic model (lower precision, deeper bounded unroll cap, branch pruning, AST+env memoization) — design tradeoffs around precision vs speed, not optimizations of a single hot loop. Those belong in a separate proposal, not a perf-audit follow-up.

Older notes (kept for context): the pre-decomposition guesses walked per statement to find DeclRef writes; the result is used to invalidate octagon entries.

  • getParentMapContext() / parent-map queries — clang's parent lookup, allocated lazily but consulted frequently.
  • buildNonNullAtBlockEntry — pre-pass that walks the entire CFG to compute per-block non-null facts; runs at the start of every walkCFG.
  • BranchLivenessBuilder + WriteCollector — ancillary per-function RecursiveASTVisitor passes (~4× per function).
  • liveAtJoin(is) — live-set computation per if-statement.

Remediation targets (ranked by likely payoff):

  1. Cache collectWrittenVars per statement — landed. Memoizes a deterministic per-stmt result by Stmt* pointer; 5 call sites previously re-walked the same subtree (octagon invalidation in walk() / walkCFG() main loops, BFS in buildNonNullAtBlockEntry's writtenIn lambda, loop-inc in unrollLoop). Architecturally sound; perf delta within run-to-run variance on a single curl scan (see "On measurement discipline").
  2. Consolidate the 6 non-null-marking maps into one. Each stmt currently consults/updates several; merging them into a single accumulator removes 5× the hash-lookup overhead.
  3. Skip refineRanges / refineOctagon when no IfStmt is in the immediate continuation. Today they fire unconditionally.
  4. Lazy buildNonNullAtBlockEntry — only run when a detector actually queries non-null facts. Currently runs for every function.

Beyond these four, the next round needs profiling-grade flame-graph data (perf, samply, Instruments) — phase-level instrumentation isolated the 304s to the walker but can't subdivide further without adding O(stmts) timers that would themselves perturb the measurement.

On measurement discipline

Cross-baseline data from this session shows ~15% run-to-run variance on the same curl invocation:

baseline (no timers):              465s
baseline (+compile-db timers):     455s
baseline (+walker/merge):          454s
baseline (+encode timer):          442s
baseline (+hook timer):            533s   ← anomalously slow run
after writtenvars cache:           451s

The baseline-hooks run is an outlier (likely system load or the ~millions of hook RAII timers compounding). After-cache lands at 451s, statistically indistinguishable from the 442–465s spread of the earlier baselines. Single-run measurements at this resolution don't reliably attribute small wins.

Use bench/perf_audit_run.py for any future perf claim ≤15%. It runs fold N times against a fixed compile DB and reports median + IQR + min/max for every --profile metric:

bench/perf_audit_run.py --label baseline --runs 5
# ... apply change ...
bench/perf_audit_run.py --label after-fix --runs 5 \
    --diff docs/internal/perf-audit/runs/baseline.json

The --diff output flags moves outside 1.5×IQR as "significant". For high-confidence claims (sub-5%), bump --runs 10+ and quiesce the machine (close browsers etc.) during the window.

Other tactics worth knowing about:

  • Pin CPU frequency where the OS allows (macOS: hard; Linux: cpupower frequency-set).
  • Use samply or Instruments for absolute line-level attribution; reserve --profile JSON diff for monitoring large regressions only.

The instrumentation that landed in this audit survives this variance — it's about relative attribution within one run, not absolute wall-time deltas across runs.

3. Cross-TU priming = one extra full AST walk per TU

Observed cost: baked into the 146s unaccounted bucket; not isolated yet.

Where: src/cli/scan_runner.cpp:1109-1115. Before detector dispatch, every TU is walked once to populate CrossTUCache with "this function dereferences param 2", "this function returns null sometimes", etc. The cache lives one scan and dies.

Remediation sketch: persist CrossTUCache to disk like IncrementalCache. Cache key: (qualified name, body hash). Reuse across runs unless the body changed.

Estimated payoff: the priming pass takes roughly 1× the detector AST-walk cost, so eliminating it on warm scans saves ~30–60s on curl. Needs measurement.

4. --incremental is mutually exclusive with --processes >1

Observed cost: users pick speed (parallel) OR freshness (incremental); never both.

Where: src/cli/scan_router.cpp:210-212. The incremental implementation runs serially because the parent-side fingerprint map can't be sharded today.

Remediation sketch: sharded fingerprint files per worker; parent merges at completion. Already partially modelled by SubprocessFanout's NDJSON merge.

Estimated payoff: for users on big repos who re-scan frequently (CI runs, IDE), the speedup multiplies — incremental already skips most functions; pairing with fanout gives near-zero warm-scan times.

5. ExprCache lifetime is per-TU instead of per-scan

Observed cost: unmeasured but bounded by Z3 query time (~3s across the whole scan, per [solver-profile] z3_time_ms summed). Small absolute payoff today but rises with detector heaviness.

Where: src/cli/scan_runner.cpp:1511. ExprCache is cleared at each TU boundary. Same arithmetic expression queried in TU A and TU B re-solves from scratch.

Remediation sketch: extend lifetime to per-scan, with the canonical expression hash as the key. Risk: if two different expressions canonicalise to the same hash (collision), we'd return the wrong cached result. Audit the hash function for non-collision properties before changing lifetime.

Estimated payoff: small on curl (Z3 is already cheap here); larger on z3-heavy targets (loops, complex bit manipulation).

6. Security-detector path fans out to 7 walks when ≤1 is enabled

Observed cost: zero today (the audit baseline runs >1, so the composite path activates).

Where: src/cli/scan_runner.cpp:1890-1995 — use_composite_security_walk only flips on when enabledSecurityDetectorCount() > 1. If a user runs --detectors null-deref alone, we fall back to 7 independent walks.

Remediation sketch: drop the fallback; always use the composite walker even for single-detector runs. The composite walker handles the single-detector case correctly already.

Estimated payoff: negligible for default runs; clean-up for single-detector debugging paths.

Lower-priority items

Item Where Estimated payoff
Dup CFG-build elimination (dead-statement + security walker build same CFG) src/detect/dead_statement.cpp:66 + src/ir/cfg_walker.cpp:21 small (CFG build ≪ encoder)
5 hash/tokenize walks per function in clone phase src/frontend/ast_visitor.cpp:174-180 ~170 ms on curl (clone is 0.05% of total)
Suppressions/baseline reparsed every command src/report/triage.cpp:73-90 trivial

The hash-walk fusion was the plan's highest-leverage target before the baseline. Empirically it's ~0.04% of total — keep it on the backlog for cleanliness, not perf.

Fold-on-fold findings (summary)

Full triage in docs/internal/perf-audit/fold-on-fold.md. Top patterns worth refactoring:

  • mixHash 5+ copies across security-detector anonymous namespaces. Lift to a shared helper.
  • supportsParam / collectConjuncts repeated across detectors. Move to a src/symbolic/z3_helpers.{hpp,cpp} sibling of the existing z3_model_support.
  • onFunctionEnd boilerplate across the 5 security observers. Default implementation in a base class.
  • ir::*::valid / operator bool / operator== boilerplate for Call, MemberRef, Symbol, Expr. CRTP or macro.

The fold-on-fold pass also surfaced 152 dead-statement findings; most are cache-layer short-circuits where a guard later in the function makes an early-return provably unreachable. Some are encoder bails that are intentionally defensive. Triage requires file-by-file review; the JSON is the full record.

Notable absence: equiv detector emitted zero findings. That's honest progress — the prior scout-rule extractions (encoder_arms, clang_type_queries, callee names) moved colliding helpers out of the per-detector files. The remaining duplication is in small helpers that don't reach equiv's signature-match threshold.

Phase-1 result: instrumentation, not the planned hash fusion

The original plan committed to fusing the 5 hash/tokenize walks into one pass as the "highest-leverage" fix. Empirically that target is 0.04% of total. Plan pivot: ship the instrumentation (3 new ScanProfile fields: compile_db_load_ms, fanout_orchestration_ms, serial_dispatch_ms) so subsequent rounds have phase-level data instead of a flat per-detector list. Commit: 503799a.

Result: the 146s previously-unaccounted bucket is now named (serial_dispatch_ms - sum(detector.wall_ms)) and the next optimisation round can target it specifically.

Phase-2 backlog (ranked by estimated payoff, after measurement)

For Z3 and Clang library-expansion opportunities (separate axis from this backlog), see library-expansion-matrix.md — 20 scored rows with file-cited insertion sites and a recommended top-3 sequence.

The first two items below shipped in the same round as the audit. They are kept on the list because each surfaced a measurement worth recording.

  1. Persist CrossTUCache across scans — SHIPPED, ~8s wall (~2%). v2 reaches 100% hit rate and exact finding-count parity (7112==7112 on curl null-deref). The audit's 30–60s estimate was inflated 3–6×; actual priming cost on curl is ~9s and v2 saves essentially all of it. Treat the cache as a correctness invariant for incremental scans + small wall win + infrastructure for future caching. Design + measurement: docs/internal/perf-audit/cross-tu-cache-persistence.md.
  2. Per-phase null-deref decomposition — SHIPPED, identified 89% bucket. Four new timers (cfg_build_ms, nonnull_precompute_ms, control_walk_ms, stmt_overhead_ms) resolve the previously-unattributed null-deref walker time. The 89% turned out to be control_walk_ms (recursive control- flow body walks), not per-stmt bookkeeping. See the null-deref section above for the full breakdown.
  3. --incremental + --processes >1 compatibility. Requires sharded fingerprint files.
  4. ExprCache lifetime extension to per-scan (with collision audit).
  5. Always-on composite security walker (drop the ≤1 fallback). Attempted as a ~115-line cleanup (delete the 7 if (!use_composite && detectorEnabled(...)) blocks, force the composite path). Build + 47/47 tests stayed green, but the curl A/B at the standard --budget-seconds 5 showed up to ~1.5% finding drift across runs against the same code, indistinguishable from the ~0.8% run-to-run noise observed between back-to-back identical reruns. Reverted pending a longer-budget parity check (60s/TU, ~30 min per leg) that can separate semantic drift from budget-truncation noise.
  6. Dup CFG-build elimination (small).
  7. Hash-walk fusion (cleanliness, ~170ms).
  8. Fold-on-fold refactor: mixHash, supportsParam, onFunctionEnd, ir::* boilerplate. Cleanliness.
  9. PCH for project headers — measured ceiling ~0.3% wall. Keep on the list for documentation but do not invest design effort until the 89% bookkeeping bucket is decomposed and proven not to dominate.

Regression prevention

Recommended addition to bench/run_curl_ab.py: capture the new phase timings (compile_db_load_ms, fanout_orchestration_ms, serial_dispatch_ms) alongside per-detector wall_ms. Diff the JSON against docs/internal/perf-audit/baseline-instrumented-2026-05-23.json on each release; alert on >10% regression in any phase.

The bench harness already parses --profile JSON; only the field list needs extending.

Pointers

  • Baseline JSON: docs/internal/perf-audit/baseline-instrumented-2026-05-23.json
  • Fold-on-fold JSON: docs/internal/perf-audit/fold-on-fold-2026-05-23.json
  • Fold-on-fold triage: docs/internal/perf-audit/fold-on-fold.md
  • Instrumentation commit: 503799a
  • Fold-on-fold commit: (this series)
  • Audit commit (this doc): (HEAD)