fix(audit): break audit_log_path/_session_id deadlock

Pre-existing latent bug since d9e32e5: ``audit_log_path()`` acquires
the non-reentrant ``_LOCK`` and, while holding it, calls
``_session_id()`` which also takes ``_LOCK``. On a clean module state
(both ``_LOG_PATH`` and ``_SESSION_ID`` unset) the first caller
deadlocks.

``log_session_start`` triggers it in practice — it's the first GUI
call after import and the ``log_file=str(audit_log_path())`` arg is
evaluated before any ``log_event`` has had a chance to lazy-init the
session id. Strong candidate contributor to the blank-pages symptom
the kill switch was put back to mask: the writer thread (and any
producer reaching ``audit_log_path``) would freeze forever, and
Ctrl+C would not free the GIL — matches the launcher-can't-be-killed
behaviour reported in 1caedbb.

Fix: resolve the session id BEFORE acquiring ``_LOCK`` in
``audit_log_path``. ``_session_id`` already double-checks under its
own lock, so the call is safe and self-synchronising.

Test fixture in ``tests/test_audit.py`` now bypasses the kill switch
via ``monkeypatch.setattr(audit, "_DISABLED", False)`` — env vars are
captured at import time and ``monkeypatch.setenv`` won't reach the
module-level flag. With the fix in place, all 6 tests pass in 0.15s;
without it, ``test_session_start_renders`` (and any test exercising
the log_session_start path) hangs indefinitely.

Kill switch behaviour is unchanged in production (`_DISABLED = True`
in the shipped module); this is purely a correctness fix for the
code path that gets exercised when the switch is off.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
2026-05-19 14:45:08 +00:00
parent 4451f74895
commit a8ff8f4bd0
2 changed files with 13 additions and 2 deletions

View File

@@ -121,13 +121,18 @@ def audit_log_path() -> Path:
""" """
global _LOG_PATH global _LOG_PATH
if _LOG_PATH is None: if _LOG_PATH is None:
# Resolve the session id BEFORE acquiring _LOCK. ``_session_id``
# also takes ``_LOCK`` to write its first value, and the lock
# is non-reentrant — nesting them deadlocks the first caller
# in a clean module state. (Hit in ``log_session_start`` since
# it's the first GUI call and both globals are unset.)
sid = _session_id()[:8]
with _LOCK: with _LOCK:
if _LOG_PATH is None: if _LOG_PATH is None:
try: try:
ts = datetime.now(tz=timezone.utc).strftime("%Y%m%dT%H%M%SZ") ts = datetime.now(tz=timezone.utc).strftime("%Y%m%dT%H%M%SZ")
except Exception: except Exception:
ts = "unknown" ts = "unknown"
sid = _session_id()[:8]
_LOG_PATH = audit_log_dir() / f"datatools-{ts}-{sid}.jsonl" _LOG_PATH = audit_log_dir() / f"datatools-{ts}-{sid}.jsonl"
return _LOG_PATH return _LOG_PATH

View File

@@ -26,9 +26,14 @@ import pytest
@pytest.fixture @pytest.fixture
def isolated_audit(monkeypatch, tmp_path): def isolated_audit(monkeypatch, tmp_path):
"""Redirect audit writes into ``tmp_path`` and reset module state """Redirect audit writes into ``tmp_path`` and reset module state
so each test starts fresh.""" so each test starts fresh.
The kill switch is bypassed for the duration of the test by
patching the module-level constant directly — these tests need
the real producer path to run."""
monkeypatch.setenv("DATATOOLS_AUDIT_DIR", str(tmp_path)) monkeypatch.setenv("DATATOOLS_AUDIT_DIR", str(tmp_path))
from src import audit from src import audit
monkeypatch.setattr(audit, "_DISABLED", False)
audit.reset_for_tests() audit.reset_for_tests()
yield audit yield audit
# Best-effort cleanup so a runaway writer thread doesn't keep # Best-effort cleanup so a runaway writer thread doesn't keep
@@ -115,6 +120,7 @@ class TestUnwritableTargetDoesntCrash:
not_a_dir.write_text("hi") not_a_dir.write_text("hi")
monkeypatch.setenv("DATATOOLS_AUDIT_DIR", str(not_a_dir)) monkeypatch.setenv("DATATOOLS_AUDIT_DIR", str(not_a_dir))
from src import audit from src import audit
monkeypatch.setattr(audit, "_DISABLED", False)
audit.reset_for_tests() audit.reset_for_tests()
try: try:
start = time.perf_counter() start = time.perf_counter()