os-sdlc test suite regressed from 21 s to 112-129 s; three causes, fix and add a guard against reversion #624

Closed
opened 2026-09-22 19:16:46 +00:00 by jared · 3 comments
Owner

Context

Suite timings were reviewed during session 878aaacc after implementation 10 on ticket #557 showed abnormally slow gate runs. Body rewritten 2026-09-22 (session c15fe063) after a design review showed the speed causes trace to one design error: production code that writes process-global state, or hides a process start behind a default argument.

Observed

ruby tests/all.rb takes 112-129 s wall for 1378 tests at 179% CPU on a 12-CPU machine. The 2026-08-23 tree (090c0b17) ran 1035 tests in 20.9 s at 437% CPU. For 83 of 112 s only one test was running.

Causes, with evidence:

  1. Process-global writes in production. lib/os_sdlc/model/project_shell.rb:15,19 wraps Open3 in Bundler.with_unbundled_env, which rewrites ENV for the whole process during the child's lifetime; lib/os_sdlc/lsp_probe/open_session.rb:21 does the same with with_original_env. lib/os_sdlc/model/run_timestamp.rb:24-28 swaps ENV["TZ"]. RunTimestamp has zero callers in lib or tests (last caller pruned in cb3207de): it is dead code.
  2. stay_serial! marks without a cause. ~179 tests across 28 classes carry the mark. Sampled classes (CliNextInstructionTest, PostToolUseTest, CliSubagentStartTest, GateCliTest) touch no ENV, no chdir, and use their own mktmpdir. The marks were copied from the 090c0b17 header, not proven. Each serial test also drains the parallel pool (Minitest.run_test_exclusively in tests/test_helper.rb) and waits for any 10-16 s lsp/evidence test in flight: 17-33 s wall. Serial tests also average 0.35 s vs 0.06 s in August (OpenImplementation, per-test SQLite schema recreation, TeaTracker#fetch_body on every open).
  3. A daemon hidden in a default argument. lib/os_sdlc/evidence/fingerprint.rb:14 defaults lsp_runner: to a real LspProbe::SharedRunner(spawner: LspProbe::Daemon). ReportTest 0.52 -> 22.8 s, FingerprintTest 0.39 -> 13.8 s; each test pays a daemon start plus the 2.0 s stop timeout (daemon/stopper.rb:7). The "LSP daemon spawn timeout" flakes in programmer gates (2 of 5 red gates in dispatch 125) are most likely these daemons under load.

Reproduce

ruby tests/all.rb

Expected

Fix order follows correctness, not diff size:

  1. Delete RunTimestamp and its test.
  2. Pass env hashes to Open3 (Open3.capture3(Bundler.unbundled_env, command)) in ProjectShell and OpenSession. No production code mutates ENV or Bundler env in-process.
  3. Make lsp_runner: a required argument of Evidence::Fingerprint; build the real runner once at the composition root. Real daemons only in lsp_integration_test.rb and lsp_probe_bin_test.rb; make the connect deadline injectable.
  4. Remove every stay_serial!, run the suite in parallel, fix each real failure at the shared state it names. Keep run_test_exclusively only for a class that step 4 proves needs it, with the reason recorded on the class.
  5. Fix the serial drain ordering in test_helper only if any serial class survives step 4.
  6. Reversion guard: a suite wall-time budget assertion, and a check that LspProbe::Daemon appears only in the two integration test files.

Estimate: 20-25 s wall after all steps (not measured).

Origin

  • Trigger: implementation 10 gate timings on #557
  • Chain: slow suite gate <- serial tests + hidden daemon <- DESIGN (process-global writes in project_shell.rb, open_session.rb, run_timestamp.rb; default-argument daemon in fingerprint.rb)
  • Root candidate: this ticket
  • Session: 878aaacc (evidence), c15fe063 (design review + implementation)
  • Ticket-skeptic verdict: CREATE
  • Note: must land BEFORE #625 (diff-test fallback silently runs the full suite when any changed file is unmapped).

Cases

  1. ruby tests/all.rb wall time is under 35 s on the same machine, with 0 failures.
  2. No production code mutates ENV or Bundler env in-process; child processes receive env explicitly.
  3. RunTimestamp no longer exists.
  4. Evidence::Fingerprint requires lsp_runner:; Fingerprint/Report unit tests do not spawn a real daemon.
  5. No test class carries stay_serial! without a recorded reason.
  6. A guard fails loudly when the suite exceeds its time budget or LspProbe::Daemon is referenced outside the two integration test files.
## Context Suite timings were reviewed during session 878aaacc after implementation 10 on ticket #557 showed abnormally slow gate runs. Body rewritten 2026-09-22 (session c15fe063) after a design review showed the speed causes trace to one design error: production code that writes process-global state, or hides a process start behind a default argument. ## Observed `ruby tests/all.rb` takes 112-129 s wall for 1378 tests at 179% CPU on a 12-CPU machine. The 2026-08-23 tree (090c0b17) ran 1035 tests in 20.9 s at 437% CPU. For 83 of 112 s only one test was running. Causes, with evidence: 1. **Process-global writes in production.** `lib/os_sdlc/model/project_shell.rb:15,19` wraps Open3 in `Bundler.with_unbundled_env`, which rewrites ENV for the whole process during the child's lifetime; `lib/os_sdlc/lsp_probe/open_session.rb:21` does the same with `with_original_env`. `lib/os_sdlc/model/run_timestamp.rb:24-28` swaps `ENV["TZ"]`. RunTimestamp has zero callers in lib or tests (last caller pruned in cb3207de): it is dead code. 2. **`stay_serial!` marks without a cause.** ~179 tests across 28 classes carry the mark. Sampled classes (CliNextInstructionTest, PostToolUseTest, CliSubagentStartTest, GateCliTest) touch no ENV, no chdir, and use their own mktmpdir. The marks were copied from the 090c0b17 header, not proven. Each serial test also drains the parallel pool (`Minitest.run_test_exclusively` in tests/test_helper.rb) and waits for any 10-16 s lsp/evidence test in flight: 17-33 s wall. Serial tests also average 0.35 s vs 0.06 s in August (OpenImplementation, per-test SQLite schema recreation, TeaTracker#fetch_body on every open). 3. **A daemon hidden in a default argument.** `lib/os_sdlc/evidence/fingerprint.rb:14` defaults `lsp_runner:` to a real `LspProbe::SharedRunner(spawner: LspProbe::Daemon)`. ReportTest 0.52 -> 22.8 s, FingerprintTest 0.39 -> 13.8 s; each test pays a daemon start plus the 2.0 s stop timeout (daemon/stopper.rb:7). The "LSP daemon spawn timeout" flakes in programmer gates (2 of 5 red gates in dispatch 125) are most likely these daemons under load. ## Reproduce ruby tests/all.rb ## Expected Fix order follows correctness, not diff size: 1. Delete RunTimestamp and its test. 2. Pass env hashes to Open3 (`Open3.capture3(Bundler.unbundled_env, command)`) in ProjectShell and OpenSession. No production code mutates ENV or Bundler env in-process. 3. Make `lsp_runner:` a required argument of Evidence::Fingerprint; build the real runner once at the composition root. Real daemons only in lsp_integration_test.rb and lsp_probe_bin_test.rb; make the connect deadline injectable. 4. Remove every `stay_serial!`, run the suite in parallel, fix each real failure at the shared state it names. Keep `run_test_exclusively` only for a class that step 4 proves needs it, with the reason recorded on the class. 5. Fix the serial drain ordering in test_helper only if any serial class survives step 4. 6. Reversion guard: a suite wall-time budget assertion, and a check that `LspProbe::Daemon` appears only in the two integration test files. Estimate: 20-25 s wall after all steps (not measured). ## Origin - Trigger: implementation 10 gate timings on #557 - Chain: slow suite gate <- serial tests + hidden daemon <- DESIGN (process-global writes in project_shell.rb, open_session.rb, run_timestamp.rb; default-argument daemon in fingerprint.rb) - Root candidate: this ticket - Session: 878aaacc (evidence), c15fe063 (design review + implementation) - Ticket-skeptic verdict: CREATE - Note: must land BEFORE #625 (diff-test fallback silently runs the full suite when any changed file is unmapped). ## Cases 1. `ruby tests/all.rb` wall time is under 35 s on the same machine, with 0 failures. 2. No production code mutates ENV or Bundler env in-process; child processes receive env explicitly. 3. RunTimestamp no longer exists. 4. Evidence::Fingerprint requires `lsp_runner:`; Fingerprint/Report unit tests do not spawn a real daemon. 5. No test class carries `stay_serial!` without a recorded reason. 6. A guard fails loudly when the suite exceeds its time budget or `LspProbe::Daemon` is referenced outside the two integration test files.
Author
Owner

Body rewritten 2026-09-22 in session c15fe063: fix order now follows correctness (dead RunTimestamp, env hashes to Open3, required lsp_runner, remove every stay_serial! and fix what breaks). Implemented in-session, not via /os-sdlc:implement, because the pipeline is the thing being repaired. Old body preserved in the session scratchpad.

Body rewritten 2026-09-22 in session c15fe063: fix order now follows correctness (dead RunTimestamp, env hashes to Open3, required lsp_runner, remove every stay_serial! and fix what breaks). Implemented in-session, not via /os-sdlc:implement, because the pipeline is the thing being repaired. Old body preserved in the session scratchpad.
Author
Owner

Resolution

Done: Merged to main cf017e0c (7 commits + ADR-0205). ProjectShell/OpenSession pass env hashes to Open3; Evidence::Fingerprint requires lsp_runner: with the evidence CLI owning one SharedRunner; dead RunTimestamp deleted; all 28 stay_serial! marks and run_test_exclusively removed and each real shared-state failure fixed at its source (GateVerdict root:/chdir, RootSearch home:, per-thread popen3 stub, subprocess env tests); guards: tests/lsp_probe_real_daemon_guard_test.rb and OS_SDLC_SUITE_BUDGET_S (default 60) in tests/all.rb. Implemented in session, not via /os-sdlc:implement.

Evidence: Suite 115.5 s (1382 tests) -> 44.7/45.3/52.6 s (1388 tests, 0 failures, 3 runs). Cases 2-6 verified: no ENV/Bundler mutation in lib, RunTimestamp gone, Fingerprint requires lsp_runner:, zero stay_serial! in tests, both guards verified to fail when tripped. ADR-0205 amends 0191/0198; ADR-0191 affected-paths corrected.

Follow-ups: none captured; the 35 s gap is the review question above

Needs review: Case 1 asks for under 35 s; measured 44.7 / 45.3 / 52.6 s. Decide: accept the 60 s budget as shipped, or reopen for the remaining gap (EvidenceBinTest real-root scan ~15 s is the largest single test).

## Resolution **Done:** Merged to main cf017e0c (7 commits + ADR-0205). ProjectShell/OpenSession pass env hashes to Open3; Evidence::Fingerprint requires lsp_runner: with the evidence CLI owning one SharedRunner; dead RunTimestamp deleted; all 28 stay_serial! marks and run_test_exclusively removed and each real shared-state failure fixed at its source (GateVerdict root:/chdir, RootSearch home:, per-thread popen3 stub, subprocess env tests); guards: tests/lsp_probe_real_daemon_guard_test.rb and OS_SDLC_SUITE_BUDGET_S (default 60) in tests/all.rb. Implemented in session, not via /os-sdlc:implement. **Evidence:** Suite 115.5 s (1382 tests) -> 44.7/45.3/52.6 s (1388 tests, 0 failures, 3 runs). Cases 2-6 verified: no ENV/Bundler mutation in lib, RunTimestamp gone, Fingerprint requires lsp_runner:, zero stay_serial! in tests, both guards verified to fail when tripped. ADR-0205 amends 0191/0198; ADR-0191 affected-paths corrected. **Follow-ups:** none captured; the 35 s gap is the review question above Needs review: Case 1 asks for under 35 s; measured 44.7 / 45.3 / 52.6 s. Decide: accept the 60 s budget as shipped, or reopen for the remaining gap (EvidenceBinTest real-root scan ~15 s is the largest single test).
Author
Owner

Resolution

Done: Suite 115.5 s → 44.7/45.3/52.6 s; cases 2–6 met; env-hash discipline, lsp_runner require, RunTimestamp deleted, every stay_serial! removed, reversion guards shipped. Merged main cf017e0c, ADR-0205.

Evidence: 3 full-suite runs, 1388 tests, 0 failures; os-sdlc leaf History row present in docs/implementation-status/os-sdlc.md.

Follow-ups: Case 1 (<35 s) not met; accepted 60 s budget. Remaining gap tracked by #628, #631, #633.

## Resolution **Done:** Suite 115.5 s → 44.7/45.3/52.6 s; cases 2–6 met; env-hash discipline, lsp_runner require, RunTimestamp deleted, every stay_serial! removed, reversion guards shipped. Merged main cf017e0c, ADR-0205. **Evidence:** 3 full-suite runs, 1388 tests, 0 failures; os-sdlc leaf History row present in docs/implementation-status/os-sdlc.md. **Follow-ups:** Case 1 (<35 s) not met; accepted 60 s budget. Remaining gap tracked by #628, #631, #633.
jared closed this issue 2026-09-23 13:10:45 +00:00
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
jared/cc-os#624
No description provided.