FixedReproduced on demandcause established — the ordering is now harmless

test_select_sees_committed_row

test_R02_commit_before_select.py · failed in 40% of captured runs

Forcing db_select to start before db_commit reproduced the failure on every attempt, so that ordering is a sufficient condition for the failure.

The two operations in `proven_inversion` name the same `resource`, and one has `access: 'write'` while the other has `access: 'read'`. The reader observed state the writer had not yet published.

Where the two runs diverge

The same test, twice, on a shared time axis. The outlined pair is the ordering that differs.

The same test twice on a shared time axis. Each operation is anchored at the moment it started. In the failing run db_select#0 starts before db_commit#0, and db_commit never ran at all.
Passing run3 operations in 1.36 ms
db_commit
db_select
assert
Failing run2 operations in 0.14 ms
db_select
assert
db_commit — never ran
0 ms0.68 ms1.36 ms

Outlined: db_select#0 starts before db_commit#0 in the failing run, and after it when the test passes.

db_commit never started in the failing run. The run flushed its spans normally, so that absence is evidence: the operation had not happened by the time the assertion read the state.

Evidence

Suspicion comes from comparing runs. The decision comes from forcing the ordering and seeing what happens.

OrderingSuspiciousnessWhen forcedVerdict
db_select#0 → db_commit#0the assertion depends on this1.00fails 100%reproduces the failure every time it is forced

One scheduling constraint is enough to reproduce this failure.

Policy gate

Every check the proposed patch had to pass before it was allowed to run.

All 15 checks passed. A patch runs only when every one of them does.

Refused shortcuts

  • no sleep calls introduced
  • no aliased sleep imports introduced
  • no timeout marker added or inflated
  • no retry or flaky decorator added
  • no retry loop wrapped around the assertion
  • no assertion removed or weakened
  • no exception handler swallowing the failure
  • no test skipped, xfailed or renamed out of collection

Required substance

  • a real synchronization primitive was added
  • the primitive is reachable from both the signal and the wait site
  • the patch is not a no-op

Structural safety

  • the proposed wait edge creates no wait-for cycle
  • no production-scope file modified without opt-in
  • no third-party or vendored file modified
  • the patched module parses

Verification

What was established, and at which strength. A weaker check is never presented as proof.

  • Reproduced the exact interleaving on demand

    before the fix it failed every time under the forced ordering; after the fix it passed every time under the identical ordering (confirmed)

  • Adversarial schedules

    not attempted for this incident, and so not claimed

  • Residual flake check

    20 of 20 ordinary runs stable, against 9 failures in the same number of runs before the fix

Measured overhead
+0.359 msno fixed delay introduced
Isolation
one process per run
Reproduction seed
random_seed_base 1729random_seed_sweep 1729..1733pythonhashseed 0python_version 3.12.13forced_order db_select#0 -> db_commit#0
Regression guard (executed and confirmed)
benchmark/cases/R02_commit_before_select/test_R02_commit_before_select.py::test_chronotrace_regression_c355d54b

Proposed change

Nothing is merged automatically. This is a diff for a human to review.

--- a/benchmark/cases/R02_commit_before_select/test_R02_commit_before_select.py
+++ b/benchmark/cases/R02_commit_before_select/test_R02_commit_before_select.py
@@ -6,6 +6,18 @@
 
 from benchmark.support import io_latency
 from chronotrace.capture.instrument import assertion, operation
+from chronotrace.schedule.harness import ScheduleHarness, force_order
+
+_chronotrace_gate_db_rows = asyncio.Event()
+
+
+@pytest.fixture(autouse=True)
+def _chronotrace_reset_db_rows():
+    """Provide a fresh synchronization gate for each test."""
+    global _chronotrace_gate_db_rows
+    _chronotrace_gate_db_rows = asyncio.Event()
+    yield
+
 
 ROWS: list[dict[str, str]] = []
 
@@ -14,11 +26,13 @@
 async def db_commit(row: dict[str, str]) -> None:
     """Commit a row into the table."""
     ROWS.append(row)
+    _chronotrace_gate_db_rows.set()
 
 
 @operation("db_select", resource="db.rows", access="read")
 async def db_select(key: str) -> dict[str, str] | None:
     """Select the row with ``key``."""
+    await _chronotrace_gate_db_rows.wait()
     return next((row for row in ROWS if row["id"] == key), None)
 
 
@@ -37,3 +51,19 @@
     with assertion("db.rows"):
         assert row is not None
     await tx
+
+
+@pytest.mark.asyncio
+async def test_chronotrace_regression_c355d54b() -> None:
+    """Reproduce the interleaving that used to fail, deterministically.
+
+    Generated by ChronoTrace for incident c355d54b. Before the repair this
+    race appeared in roughly 40% of runs; this guard forces the
+    exact ordering that caused it, so a regression fails here on every run
+    rather than once in a while.
+    """
+    forced_order = ['db_select#0', 'db_commit#0']
+    harness = ScheduleHarness(forced_order, timeout_s=5.0)
+    with force_order(harness):
+        await test_select_sees_committed_row()
+    assert harness.reached == forced_order
← All incidents