Repository navigation
P0: performanceSmoke / safariUnfuckerRegressionTest wall-clock threshold failures under host load (found during #144 Validate) - #147
Conversation
… threshold tests (#146) performanceSmoke: Date() -> ContinuousClock; corrected the misapplied "ADR 012 ~1.35x" comment with fresh 14-run measurement evidence (median 3.916s, max 6.513s, no drift from #97's baseline). Limits left unchanged. safariUnfuckerRegressionTest: measureMedian iterations 1->5 (was a mislabeled single sample); Date() -> ContinuousClock; ceiling changed to max(tIsolated * 1.5, tIsolated + 0.030) so small-baseline scheduling jitter isn't a large relative overshoot. Both fixes confirmed via 14 consecutive full-suite runs under sustained host load, 0 failures. Adds ADR 039 documenting the methodology and data (038 was already claimed by #144's shutdown-snapshot work on this branch). Plan.md and the ADR index updated.
|
🏭 Fabrik — stage: Implement Everything is in order and consistent. All work is committed, pushed, and the task checklist is fully checked off. This stage is complete. Fixed both Used 3/250 turns, 0k input / 1k output tokens. |
|
🏭 Fabrik — stage: Review Nothing to commit, branch is already up to date with main (merge-base = origin/main HEAD), no rebase needed. Review FindingsVerified
FixedNone — no issues found requiring changes. BlockingNone. PR #147 is clean, well-tested, and ready for human review. Reviewed the wall-clock threshold fix for Used 24/50 turns, 0k input / 5k output tokens. |
|
🏭 Fabrik — stage: Validate CI green, PR mergeable, no unresolved TODOs. Everything checks out — this is ready to merge. Validation ReportRequirements: 6/6 verified
Test Suite: PASSED
Regressions: None detectedChanges are scoped to two test files + ADR/docs; no production code touched (measurement confirmed no code regression, so Branch/PR state
Verdict: READY TO MERGERe-verified independently: rebased/clean, 369/369 tests passing across 3 fresh debug runs plus release, both target tests ( Used 21/50 turns, 0k input / 4k output tokens. |
Closes #146
Summary
Investigate two recurring wall-clock-threshold test failures —
IndexerTests.performanceSmokeandSQLiteStorageConcurrencyTests.safariUnfuckerRegressionTest— that surfaced during #144's Validate stage under heavy shared-host contention. For each, re-measure with a rigorous methodology to determine whether the current threshold design has a code-fixable headroom problem or is operating correctly but with insufficient margin against realistic host-load variance, then apply an evidence-backed fix (absolute-floor terms, coarser ratios, and/or re-validated budgets) — never a threshold loosening without measurement evidence, and never a test-skip mechanism.Confirmed against current code on this branch:
IndexerTests.swift:393-443—performanceSmokeassertselapsed < 10.0in#if DEBUG,< 5.0in release, with a comment citing P0: Investigate LSM Indexer performanceSmoke failure — 36.5s vs 10s debug limit on Validate run #97'svDSP_maxvifix and an "ADR 012, ~1.35× CI-runner factor" derivation.SQLiteStorageConcurrencyTests.swift:110-159—safariUnfuckerRegressionTestassertstConcurrentWrites < tIsolated * 1.5with no absolute floor term.adrs/012-performance-regression-thresholds.md) governs a different suite (Tests/SwitchcraftTests/Performance/PerformanceTests.swift, release-mode only, gated out entirely in debug). It does not state an explicit "1.35×" multiplier anywhere in its text — the figure cited in theperformanceSmokecomment appears to be back-derived from ADR 012's own release-mode CI-vs-local data point (~326ms / ~241ms ≈ 1.35×). Research should verify whether that derivation is even applicable toperformanceSmoke's debug-mode, async-loop-dominated workload, which has a different performance profile than the release-mode search-latency numbers ADR 012 was calibrated against.Problem
During the Validate stage for #144,
swift test(debug) failed locally on both the PR branch (fabrik/issue-144) and on unmodifiedmainat the same commit (057d506a), in a repeatable full-suite run. Each run failed a different wall-clock-threshold assertion:fabrik/issue-144, two separate full-suite runs:SQLiteStorageConcurrencyTests.safariUnfuckerRegressionTest("Bulk write loop is not stalled by a concurrent slow FTS scan") —tConcurrentWrites (0.030s / 0.028s) < ceiling (tIsolated × 1.5 = 0.028s / 0.017s). Both are ~9–60% overshoots on a sub-30ms budget.main(057d506a), one full-suite run:ConcurrencyTestsR3 ("interleaved add + search under cascading flush completes without errors") hit its 5ssearchTimedOut, andIndexerTests.performanceSmoke("indexing 5000 single-token 128-dim chunks completes within 5s") measured 15.33s vs its 10s debug limit — the same test previously investigated and fixed in P0: Investigate LSM Indexer performanceSmoke failure — 36.5s vs 10s debug limit on Validate run #97 (post-fix median was measured at 3.688s with an assumed ~9s worst case).All four failures passed when the individual test was re-run in isolation (confirmed for the SQLite concurrency test: 5/5 isolated passes at ~1s each, far under its budget). This points at contention during full-suite parallel execution, not a deterministic code defect.
Environmental context:
uptimeon the machine running this Validate stage showedload averages: 56.85 46.51 39.65againsthw.ncpu=20(i.e. ~2.5–3× oversubscribed), with 16 concurrent logged-in users — consistent with multiple concurrent Fabrik agent sessions/worktrees building and testing simultaneously on a shared box. CI (GitHub Actions, dedicated runners) is green on bothswift test (macOS)andswift test -c release (macOS)for PR #145 at the same commit.Per this project's CLAUDE.md Validate policy, "pre-existing," "flaky," and "timing-sensitive" are explicitly not valid waivers, and CI-green does not override a local failure — so this is filed as a P0 rather than dismissed, even though the evidence leans toward host-load contention rather than a code regression. Issues #95/#96/#97 previously fixed distinct instances of this same failure class (
Date()-based comparisons, unsound microbench, non-vectorized debug-mode hot loop) — this may be recurrence of #97 specifically (its assumed ~9s debug worst case has ~1s of headroom against the 10s limit, which a sufficiently loaded host can exceed) or a new instance of the general pattern inSQLiteStorageConcurrencyTests.Approach
Approach
Both failure sites get the same two-part treatment the issue asks for: (1) fix the concrete measurement-methodology bugs Research already identified (single-sample "median",
Date()instead ofContinuousClock, a ratio ceiling with no absolute floor, a misapplied "~1.35×" comment borrowed from a different suite's rejected calibration), and (2) re-measure with rigor to decide, per test, whether the resulting design is sound-with-real-headroom (document and move on) or whether a genuine regression has crept in since #97 (root-cause and fix before re-measuring). This mirrors #97's own methodology and ADR 012 §(e)'s "increase iterations before loosening" policy, which Research confirmed is directly applicable and untried here.Two things this plan deliberately does not do, both flagged in Research as out of scope / too broad:
--no-parallel) repo-wide. Research identified this as the likely dominant structural contention source, but fixing it touches all 274 tests' CI runtime and blast radius, not just the two sites in scope. It gets documented as a known limitation in the new ADR, with a suggested follow-up issue, not fixed here.ConcurrencyTestsR3 5ssearchTimedOutfailure — explicitly out of scope per the issue.For
performanceSmoke, the fix is primarily measurement + documentation, not code: Research found thevDSP_maxvifix from #97 is intact,add()is simple, and whileperformFlush()changed substantially under #137, no obviously reintroduced non-vectorized loop was found. The task checklist below makes the re-measurement a real fork: if fresh data confirms the #97-era headroom holds, fix the comment and clock; if it shows real drift, root-causeperformFlush()before re-measuring.For
safariUnfuckerRegressionTest, the fix is a direct application of the existing in-repoIndexerConflictRecoveryTestsprecedent (ratio ceiling OR'd with an absolute floor) plus fixing themeasureMedian(iterations: 1)mislabeling bug, which Research identified as a real, host-load-independent source of the ceiling's own noise.A new ADR (038) generalizes the resulting pattern, since Research found two existing precedents (
IndexerConflictRecoveryTests's floor-OR-ratio,LazyLedgerBenchmarkTests's debug-ratio/release-ceiling split) that were never written up as a reusable pattern — this issue's two fixes become the third, and first documented, instance.New/Modified Files
Tests/SwitchcraftTests/IndexerTests.swiftperformanceSmoke: switchDate()→ContinuousClock; replace the misapplied "ADR 012 ~1.35×" comment with fresh measurement evidence and an accurate rationale; adjust the debug/release limits only if measurement shows real driftTests/SwitchcraftTests/SQLiteStorageConcurrencyTests.swiftmeasureMedian: bump default iterations for baseline measurements;safariUnfuckerRegressionTest: switchDate()→ContinuousClock, add absolute-floor term to the ceiling, update inline comment with fresh evidenceSources/SwitchcraftCore/Indexer/Indexer.swiftperformanceSmokemeasurement shows real regression from #97's baseline; root-cause and fixperformFlush()'s hot pathadrs/038-wall-clock-threshold-assertions.mdContinuousClock/iteration-count design pattern for wall-clock threshold assertions across the test suitedocs/Plan.mdKey Decisions
measureMedian(iterations: 1)is mislabeled (single sample, not a median) and is a real, host-load-independent contributor to the ceiling's ~65% swing. Per ADR 012 §(e).3 ("increase iterations before loosening"), this gets fixed first, and its effect gets measured, before deciding whether the 1.5× ratio itself needs adjustment. Rejected alternative: just loosen the ratio — this would paper over a measurement bug instead of fixing it, and the issue explicitly forbids threshold-loosening without measurement evidence.ContinuousClockoverDate()for hygiene, not as "the fix.·" MatcheslivenessTest's P0: Fix flaky SQLite WAL livenessTest — replace Date() comparison with monotonic clock, remove CI skip #95 precedent and removes an NTP/wall-clock-adjustment risk class, but Research is explicit that this won't reduce the magnitude of contention-driven overshoots — under real CPU contention the extra time is real, not a measurement artifact. Both fixes ship together; neither is claimed to solve the other's problem.max(ratio, additive slack), not an OR'd ceiling. The issue's own suggested form ismax(tIsolated * 1.5, isolatedTime + fixedSlackMs);IndexerConflictRecoveryTests' precedent (ratio <= 2.0 || crossingElapsed < 2.0) is a different but related shape (ratio OR absolute ceiling). Using the issue's own suggestedmax()form forsafariUnfuckerRegressionTestkeeps the fix scoped to what was asked, while the ADR documents both shapes as valid variants of the same pattern for future use.performanceSmoke's 10s/5s limits are not adjusted unless measurement proves drift. Given P0: Investigate LSM Indexer performanceSmoke failure — 36.5s vs 10s debug limit on Validate run #97's fix is confirmed intact and no obvious new hot loop was found inperformFlush(), the default assumption is the existing budget is sound and the observed failures are attributable to Swift Testing's structural intra-process parallelism (as Research's uptime data supports) — but this is a conclusion Implement must reach with fresh evidence, not assume. If evidence contradicts this, the fix is a real code fix inperformFlush(), not a threshold bump.IndexerConflictRecoveryTestsby imitation. This crosses the "would a new contributor need to discover this without reading the code" bar.Task Checklist
performanceSmokein debug mode: ≥11 full-suiteswift testruns (not--filter— Research found isolated runs structurally can't reproduce the intra-process contention that caused the original failures), recording per-run elapsed time anduptimeat each run. Prefer a quieter host window if available; if not, report load figures alongside the data rather than discarding it.performFlush()'s post-perf(indexer): lazy embedding materialization — store bucket refs in ledger, reconstruct on-demand at compaction time #137 hot path before proceeding, then re-measure with a fresh ≥11-run set.performanceSmoke: switch theDate()-based timer toContinuousClock. Replace the existing comment's "ADR 012, ~1.35× CI-runner factor" derivation (Research confirmed this figure is misapplied — it's from a discarded debug-mode calibration for a different, release-mode-only suite) with the fresh measurement evidence and an accurate statement of the actual contention source (Swift Testing's default intra-process parallelism, not CI-vs-local variance).SQLiteStorageConcurrencyTests.measureMedian: bump the defaultiterationsparameter used fortIsolatedfrom 1 to a value chosen from fresh evidence (start with 5, per ADR 012's iteration-before-loosening policy) so it's an actual median, not a mislabeled single sample.safariUnfuckerRegressionTest: switch bothtIsolatedandtConcurrentWritestiming toContinuousClock.tIsolatedbaseline across several runs (this feeds the floor constant) and add an absolute-floor term to the ceiling:ceiling = max(tIsolated * 1.5, tIsolated + fixedSlackSeconds), withfixedSlackSecondspicked from and documented against this fresh measurement (not guessed). Update the inline comment to show the derivation.swift test(debug) runs to confirm both fixed tests pass reliably; record hostuptimealongside. If the host is under heavy load, note it explicitly rather than treating it as disqualifying — the issue accepts "documented as sound with fresh evidence" as a valid outcome even under load.adrs/for the current highest-numbered file at implementation time (Research found 038 was next as of Research; confirm it's still correct before writing) and createadrs/0NN-wall-clock-threshold-assertions.md: generalize the absolute-floor/ratio design,ContinuousClockusage, and multi-iteration-median methodology; citeIndexerConflictRecoveryTestsandLazyLedgerBenchmarkTestsas prior (un-generalized) precedents and this issue's two fixes as the first documented instances; document Swift Testing's default intra-process parallelism as a known structural contention source affecting all wall-clock assertions repo-wide, with a suggested follow-up issue for anyone wanting to address it directly (not this issue's job).docs/Plan.md(appropriate section near the other recent test-infra/ADR entries) noting this fix and referencing the new ADR number — this is new work being added to the plan, not a pre-existing item being checked off, per CLAUDE.md's guidance for untracked work.swift test(debug) andswift test -c releasesuites once more after all changes land, confirming no unrelated regressions, before committing.Risks
85.11 69.57 52.00againsthw.ncpu=20, higher than the original incident). Mitigation: the task list requires reportinguptimealongside every measurement rather than assuming a quiet window; a documented "sound design, contention-driven failure" conclusion is an acceptable outcome per the issue even under load, as long as it's evidence-backed.performanceSmokemeasurement shows real drift, the root-cause work inperformFlush()is open-ended in scope — Research did not find an obvious reintroduced hot loop in its review, so this would require fresh profiling. Flagged as conditional in the task list rather than assumed necessary.fixedSlackSecondsrequires genuine jitter measurement, not a round-number guess — if the measured jitter is itself unstable across runs, that's evidence the floor needs to be conservative (biased toward the higher end of observed jitter), and the task's confirmation runs (≥10 consecutive) are the check that catches an under-provisioned floor before it merges.Used 12/50 turns, 0k input / 11k output tokens.
Verification
Fixed both
performanceSmokeandsafariUnfuckerRegressionTestwall-clock threshold flakiness: switchedDate()→ContinuousClock, fixed a mislabeled single-sample "median," and added an absolute-floor ceiling (max(ratio, tIsolated + 30ms)) validated against fresh scheduling-jitter data. Re-measuredperformanceSmokeover 14 consecutive full-suite runs under sustained heavy host load — confirmed #97's fix still holds with real headroom (median 3.9s vs 10s limit), so no threshold orperformFlush()change was needed. Documented the methodology and data in new ADR 039 (038 was already claimed by #144's work on this branch), updateddocs/Plan.md, and verified fullswift test(369/369) andswift test -c release(369/369) both pass. Noted but left out of scope per the issue's own boundary:ConcurrencyTestsR1–R4searchTimedOutrecurred in 2/14 runs — flagged in ADR 039 as a recommended follow-up issue.Closes #146