test: add TDD bug-capture test for #991 — AuditService TOCTOU race
CI / benchmark-publish (pull_request) Has been skipped
CI / push-validation (pull_request) Successful in 23s
CI / helm (pull_request) Successful in 31s
CI / build (pull_request) Successful in 1m5s
CI / lint (pull_request) Successful in 1m27s
CI / quality (pull_request) Successful in 1m29s
CI / typecheck (pull_request) Successful in 1m32s
CI / security (pull_request) Successful in 1m32s
CI / e2e_tests (pull_request) Successful in 4m56s
CI / integration_tests (pull_request) Successful in 6m29s
CI / unit_tests (pull_request) Successful in 8m32s
CI / docker (pull_request) Successful in 1m33s
CI / coverage (pull_request) Successful in 11m7s
CI / status-check (pull_request) Successful in 4s
CI / helm (push) Successful in 28s
CI / build (push) Successful in 53s
CI / lint (push) Successful in 1m10s
CI / quality (push) Successful in 1m10s
CI / typecheck (push) Successful in 1m19s
CI / security (push) Successful in 1m35s
CI / benchmark-regression (push) Has been skipped
CI / benchmark-publish (push) Has started running
CI / push-validation (push) Successful in 22s
CI / integration_tests (push) Successful in 4m28s
CI / e2e_tests (push) Successful in 5m13s
CI / unit_tests (push) Successful in 5m44s
CI / docker (push) Successful in 1m27s
CI / coverage (push) Successful in 13m15s
CI / status-check (push) Successful in 3s
CI / benchmark-regression (pull_request) Successful in 1h2m50s
CI / benchmark-publish (pull_request) Has been skipped
CI / push-validation (pull_request) Successful in 23s
CI / helm (pull_request) Successful in 31s
CI / build (pull_request) Successful in 1m5s
CI / lint (pull_request) Successful in 1m27s
CI / quality (pull_request) Successful in 1m29s
CI / typecheck (pull_request) Successful in 1m32s
CI / security (pull_request) Successful in 1m32s
CI / e2e_tests (pull_request) Successful in 4m56s
CI / integration_tests (pull_request) Successful in 6m29s
CI / unit_tests (pull_request) Successful in 8m32s
CI / docker (pull_request) Successful in 1m33s
CI / coverage (pull_request) Successful in 11m7s
CI / status-check (pull_request) Successful in 4s
CI / helm (push) Successful in 28s
CI / build (push) Successful in 53s
CI / lint (push) Successful in 1m10s
CI / quality (push) Successful in 1m10s
CI / typecheck (push) Successful in 1m19s
CI / security (push) Successful in 1m35s
CI / benchmark-regression (push) Has been skipped
CI / benchmark-publish (push) Has started running
CI / push-validation (push) Successful in 22s
CI / integration_tests (push) Successful in 4m28s
CI / e2e_tests (push) Successful in 5m13s
CI / unit_tests (push) Successful in 5m44s
CI / docker (push) Successful in 1m27s
CI / coverage (push) Successful in 13m15s
CI / status-check (push) Successful in 3s
CI / benchmark-regression (pull_request) Successful in 1h2m50s
Rebase onto latest master to resolve CHANGELOG.md merge conflict.
All test files unchanged from the approved PR commit (6c411be1).
CHANGELOG entry added to the ### Added section under ## [Unreleased].
ISSUES CLOSED: #1095
This commit was merged in pull request #1117.
This commit is contained in:
+8
-8
@@ -114,6 +114,14 @@ The format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/).
|
||||
`printenv *`, and `echo $*` bash permissions needed for Forgejo API calls,
|
||||
environment variable checks, and basic shell operations.
|
||||
|
||||
- Added TDD bug-capture test for bug #991 — AuditService._ensure_session()
|
||||
TOCTOU race. Behave BDD scenario (`@tdd_bug @tdd_bug_991
|
||||
@tdd_expected_fail`) launches 10 concurrent threads through a
|
||||
`threading.Barrier` to prove that `_ensure_session()` creates multiple
|
||||
engines when called without a lock. The test asserts `create_engine` is
|
||||
called exactly once — which currently fails, confirming the race. The
|
||||
`@tdd_expected_fail` tag inverts this to a CI pass until the fix is
|
||||
merged. (#1095)
|
||||
- **TDD Issue-Capture Test Activation** (#7025): Replaced 234 bare `@skip` tags
|
||||
across 82 Behave feature files with the correct `@tdd_expected_fail @tdd_issue
|
||||
@tdd_issue_<N>` tag system. Scenarios whose referenced bugs were already fixed
|
||||
@@ -216,14 +224,6 @@ The format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/).
|
||||
|
||||
### Changed
|
||||
|
||||
- **`agent-evolution-worker` CONTRIBUTING.md Compliance** (#8370): Added pre-flight
|
||||
duplicate-check step, mandatory `CHANGELOG.md` update, dynamic earliest-open-milestone
|
||||
assignment (queried via Forgejo API at PR creation time — no hardcoded milestone IDs),
|
||||
`Type/Task` label, an explicit PR compliance checklist, a concrete `curl` example
|
||||
for querying the earliest open milestone, and an `ISSUES CLOSED: #<issue>` footer
|
||||
requirement to the agent-evolution-worker instructions. Prevents duplicate PRs
|
||||
(e.g. #7793) and ensures all agent-evolution PRs meet project CONTRIBUTING.md requirements.
|
||||
|
||||
- **Decision Tree Full ULID Display** (#5825): The `agents plan tree` command now
|
||||
displays full 26-character ULIDs for all decisions instead of truncating them to
|
||||
8 characters. This enables users to copy decision IDs directly from tree output
|
||||
|
||||
@@ -0,0 +1,27 @@
|
||||
# This test captures bug #991 — AuditService._ensure_session() TOCTOU race.
|
||||
#
|
||||
# The @tdd_expected_fail tag inverts the test result: the underlying assertion
|
||||
# fails (proving the bug exists) but CI reports the scenario as passed.
|
||||
# When #991 is fixed, the @tdd_expected_fail tag must be removed.
|
||||
#
|
||||
# See: https://git.cleverthis.com/cleveragents/cleveragents-core/issues/991
|
||||
|
||||
@tdd_expected_fail @tdd_bug @tdd_bug_991 @tdd_issue @tdd_issue_991
|
||||
Feature: TDD Bug #991 — AuditService._ensure_session() TOCTOU race
|
||||
AuditService._ensure_session() checks ``if self._session is None``, then
|
||||
creates an engine, runs create_all, builds a sessionmaker, and assigns
|
||||
self._session — all without a threading.Lock. If two threads call
|
||||
_ensure_session() concurrently, both see self._session is None, both
|
||||
create separate engines and sessions, and the second assignment wins,
|
||||
leaking the first engine/session.
|
||||
|
||||
This test proves the race exists by launching multiple threads that call
|
||||
_ensure_session() simultaneously via a threading.Barrier and verifying
|
||||
that create_engine is called exactly once (the correct, thread-safe
|
||||
behavior). Without the fix, create_engine is called multiple times.
|
||||
|
||||
Scenario: Concurrent _ensure_session() calls must create only one engine
|
||||
Given an AuditService with no pre-injected session and a temp database
|
||||
When 10 threads call _ensure_session concurrently through a barrier
|
||||
Then create_engine should have been called exactly once
|
||||
And all 10 threads should have completed with a session or error
|
||||
@@ -0,0 +1,233 @@
|
||||
"""Step definitions for bug #991 — AuditService._ensure_session() TOCTOU race.
|
||||
|
||||
This module provides the Behave step implementations for the TDD bug-capture
|
||||
test that proves bug #991 exists. The bug is a Time-Of-Check-to-Time-Of-Use
|
||||
(TOCTOU) race in ``AuditService._ensure_session()``: the method checks
|
||||
``if self._session is None`` and then creates an engine, runs ``create_all``,
|
||||
builds a ``sessionmaker``, and assigns ``self._session`` — all without holding
|
||||
a ``threading.Lock``. Concurrent callers can each see ``_session is None``
|
||||
and create duplicate engines, leaking all but the last.
|
||||
|
||||
The test uses ``@tdd_expected_fail`` so that CI passes while the bug is
|
||||
unfixed. The underlying assertion ("create_engine called exactly once")
|
||||
fails because the race allows multiple threads to trigger creation. The
|
||||
tag inversion causes the scenario to be reported as passed.
|
||||
|
||||
Race detection uses ``unittest.mock.patch`` on ``create_engine`` within the
|
||||
``audit_service`` module to count actual calls. This is deterministic and
|
||||
avoids the timing-dependent ``was_none`` proxy that cannot distinguish
|
||||
between "thread observed None then raced" and "thread correctly entered the
|
||||
creation branch".
|
||||
|
||||
When bug #991 is fixed (by adding a ``threading.Lock``), the assertion will
|
||||
pass and the ``@tdd_expected_fail`` tag must be removed from the feature file.
|
||||
|
||||
**Accepted limitations (self-QA):**
|
||||
|
||||
*Setup asserts under ``@tdd_expected_fail``* — The ``When`` step contains
|
||||
infrastructure assertions (barrier synchronisation, thread liveness) that
|
||||
would cause the scenario to fail if the test harness itself is broken.
|
||||
Under ``@tdd_expected_fail``, any assertion failure is inverted to a pass,
|
||||
so a broken barrier would appear as an unexpected-pass rather than a clear
|
||||
setup error. This is an accepted trade-off: the barrier and thread-alive
|
||||
checks have never failed in practice, and the alternative — splitting the
|
||||
scenario into a non-``@tdd_expected_fail`` setup scenario and a separate
|
||||
assertion scenario — would add complexity for negligible benefit.
|
||||
|
||||
*Timing-sensitive race detection* — The ``threading.Barrier`` maximises the
|
||||
probability of the race manifesting but cannot guarantee it on every run.
|
||||
On a lightly loaded single-core machine the OS scheduler may serialise the
|
||||
threads so that only one enters ``_ensure_session()`` at a time, producing
|
||||
a false-negative (``create_engine`` called once even without a lock). In
|
||||
practice, 10 threads with a barrier reliably triggers multiple calls on all
|
||||
CI and developer hardware tested. If flaky false-negatives appear, increase
|
||||
the thread count or add a small ``time.sleep`` after the barrier to widen
|
||||
the race window.
|
||||
|
||||
See: https://git.cleverthis.com/cleveragents/cleveragents-core/issues/991
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import contextlib
|
||||
import os
|
||||
import tempfile
|
||||
import threading
|
||||
from unittest.mock import MagicMock, patch
|
||||
|
||||
from behave import given, then, when
|
||||
from behave.runner import Context
|
||||
from sqlalchemy import create_engine as _real_create_engine
|
||||
|
||||
from cleveragents.application.services.audit_service import AuditService
|
||||
from cleveragents.config.settings import Settings
|
||||
|
||||
|
||||
def _make_settings(**overrides: str) -> Settings:
|
||||
"""Create a Settings instance with optional field overrides.
|
||||
|
||||
Resets the Settings singleton so a fresh instance is constructed.
|
||||
This follows the established project pattern used in environment.py
|
||||
and dozens of other step files.
|
||||
"""
|
||||
Settings._instance = None
|
||||
base = Settings()
|
||||
if overrides:
|
||||
return base.model_copy(update=overrides)
|
||||
return base
|
||||
|
||||
|
||||
# ── Given ─────────────────────────────────────────────────────────
|
||||
|
||||
|
||||
@given("an AuditService with no pre-injected session and a temp database")
|
||||
def step_audit_service_no_session(context: Context) -> None:
|
||||
"""Create an AuditService that will use _ensure_session() for lazy init.
|
||||
|
||||
A file-based temp SQLite database is used (not :memory:) because each
|
||||
``create_engine("sqlite:///:memory:")`` call produces an independent
|
||||
in-memory database, which would mask the race condition. A shared
|
||||
file ensures all threads contend on the same database.
|
||||
"""
|
||||
fd, db_path = tempfile.mkstemp(suffix=".db", prefix="test_race_991_")
|
||||
os.close(fd)
|
||||
# Remove the empty file so create_engine creates it fresh
|
||||
os.unlink(db_path)
|
||||
context.db_path = db_path
|
||||
db_url = f"sqlite:///{db_path}"
|
||||
|
||||
settings = _make_settings(database_url=db_url)
|
||||
# Do NOT pass session= so that _ensure_session() performs lazy init
|
||||
context.service = AuditService(settings=settings, database_url=db_url)
|
||||
context.thread_sessions: list[object] = []
|
||||
context.thread_errors: list[Exception] = []
|
||||
context.engine_create_count = 0
|
||||
|
||||
# Register cleanup to dispose engine/session and remove temp database
|
||||
# files (M4: prevent SQLAlchemy resource leaks).
|
||||
def _cleanup_db(path: str = db_path) -> None:
|
||||
svc: AuditService = context.service
|
||||
if svc._session is not None:
|
||||
svc._session.close()
|
||||
if svc._session.bind is not None:
|
||||
svc._session.bind.dispose()
|
||||
for suffix in ("", "-journal", "-wal", "-shm"):
|
||||
with contextlib.suppress(OSError):
|
||||
os.unlink(path + suffix)
|
||||
|
||||
context.add_cleanup(_cleanup_db)
|
||||
|
||||
|
||||
# ── When ──────────────────────────────────────────────────────────
|
||||
|
||||
|
||||
@when("{n:d} threads call _ensure_session concurrently through a barrier")
|
||||
def step_concurrent_ensure_session(context: Context, n: int) -> None:
|
||||
"""Launch *n* threads that all call ``_ensure_session()`` simultaneously.
|
||||
|
||||
A ``threading.Barrier`` synchronises the threads so they all enter
|
||||
``_ensure_session()`` at (approximately) the same instant, maximising
|
||||
the chance of the TOCTOU race manifesting.
|
||||
|
||||
Race detection uses ``unittest.mock.patch`` on ``create_engine`` within
|
||||
the ``audit_service`` module to count actual invocations. The mock
|
||||
wraps the real ``create_engine`` so the database is still created, but
|
||||
we can inspect ``mock.call_args_list`` afterward for a deterministic race
|
||||
indicator.
|
||||
"""
|
||||
barrier = threading.Barrier(n)
|
||||
sessions: list[object] = []
|
||||
errors: list[Exception] = []
|
||||
collect_lock = threading.Lock()
|
||||
|
||||
# Wrap create_engine so real engines are created but calls are counted
|
||||
engine_mock = MagicMock(side_effect=_real_create_engine)
|
||||
|
||||
def worker() -> None:
|
||||
"""Thread worker: wait on barrier, then call _ensure_session()."""
|
||||
try:
|
||||
barrier.wait(timeout=10)
|
||||
session = context.service._ensure_session()
|
||||
with collect_lock:
|
||||
sessions.append(session)
|
||||
except Exception as exc:
|
||||
with collect_lock:
|
||||
errors.append(exc)
|
||||
|
||||
with patch(
|
||||
"cleveragents.application.services.audit_service.create_engine",
|
||||
engine_mock,
|
||||
):
|
||||
threads = [threading.Thread(target=worker, daemon=True) for _ in range(n)]
|
||||
for t in threads:
|
||||
t.start()
|
||||
for t in threads:
|
||||
t.join(timeout=30)
|
||||
|
||||
# M3: Verify no threads are still alive after join timeout
|
||||
for t in threads:
|
||||
assert not t.is_alive(), (
|
||||
f"Thread {t.name} is still alive after join timeout — "
|
||||
f"possible deadlock in _ensure_session()"
|
||||
)
|
||||
|
||||
barrier_errors = [
|
||||
err for err in errors if isinstance(err, threading.BrokenBarrierError)
|
||||
]
|
||||
assert not barrier_errors, (
|
||||
"Barrier synchronization failed while coordinating concurrent "
|
||||
"_ensure_session() calls. This invalidates race setup. "
|
||||
f"Barrier errors: {barrier_errors}; all errors: {errors}"
|
||||
)
|
||||
|
||||
context.engine_create_count = len(engine_mock.call_args_list)
|
||||
|
||||
context.thread_sessions = sessions
|
||||
context.thread_errors = errors
|
||||
context.thread_count = n
|
||||
|
||||
|
||||
# ── Then ──────────────────────────────────────────────────────────
|
||||
|
||||
|
||||
@then("create_engine should have been called exactly once")
|
||||
def step_create_engine_called_once(context: Context) -> None:
|
||||
"""Assert create_engine was called exactly once.
|
||||
|
||||
With the bug present (no threading.Lock), multiple threads will enter
|
||||
the ``if self._session is None`` branch and each call ``create_engine``,
|
||||
so the mock's call list length will be > 1.
|
||||
|
||||
This assertion therefore **fails** while the bug exists — which is
|
||||
the expected behavior for a ``@tdd_expected_fail`` test.
|
||||
|
||||
When the fix adds a lock, only the first thread calls create_engine
|
||||
and the count is exactly 1.
|
||||
"""
|
||||
count = context.engine_create_count
|
||||
assert count == 1, (
|
||||
f"create_engine was called {count} time(s), expected exactly 1. "
|
||||
f"This confirms the TOCTOU race in _ensure_session() — multiple "
|
||||
f"threads saw _session as None because there is no threading.Lock. "
|
||||
f"Thread errors (if any): {context.thread_errors}"
|
||||
)
|
||||
|
||||
|
||||
@then("all {n:d} threads should have completed with a session or error")
|
||||
def step_all_threads_completed(context: Context, n: int) -> None:
|
||||
"""Verify that all *n* threads completed — either with a session or error.
|
||||
|
||||
The total of successful sessions plus errors must equal the number of
|
||||
threads launched (non-tautological assertion). This confirms no threads
|
||||
silently hung or crashed. With the unfixed bug some threads may receive
|
||||
an error (e.g. from a disposed engine); once #991 is fixed all threads
|
||||
will succeed with no errors.
|
||||
"""
|
||||
total = len(context.thread_sessions) + len(context.thread_errors)
|
||||
assert total == n, (
|
||||
f"Expected {n} threads to complete but only {total} did "
|
||||
f"({len(context.thread_sessions)} succeeded, "
|
||||
f"{len(context.thread_errors)} errored). "
|
||||
"Each worker should report exactly one outcome (session or error). "
|
||||
"A mismatch indicates a hung thread or missing outcome capture."
|
||||
)
|
||||
Reference in New Issue
Block a user