Skip to content

test(backend): stabilize SEC-04 log captures against tracing callsite-interest races - #185

Merged
lnieuwenhuis merged 2 commits into
stagingfrom
fix/audit-security-logtest-staging
Sep 17, 2026
Merged

lnieuwenhuis merged 2 commits into
stagingfrom
fix/audit-security-logtest-staging

Conversation

@lnieuwenhuis

Copy link
Copy Markdown
Owner

Summary

Test-only fix for the intermittent SEC-04 capture flake (a_contentless_provider_payload_is_not_written_to_logs failing with an empty captured log). Product logging behavior is unchanged; no assertions, markers, retries, timeouts, DB gating or suite parallelism were touched.

Root cause

tracing-core caches each callsite's Interest process-wide on first execution. While at most one dispatcher has ever been registered, a first hit is resolved from the registering thread's default subscriber (Dispatchers::rebuilder() -> Rebuilder::JustOne). Under a parallel cargo-test run, a gateway test thread without a scoped subscriber could therefore cache Interest::never for the shared upstream_photo_failure callsite, silently dropping the WARN event before it reached the capturing fmt subscriber on the test thread (verified interleaving: tracing 0.1.44 / tracing-core 0.1.36 / tracing-subscriber 0.3.23, independent second look in work/security-logtest/second-look.md).

Change

apps/backend/src/legacy_api/tests/mod.rs only:

  • Register one permanent no-op (NoSubscriber) dispatch in capture_logs before the scoped capturing subscriber, so the global registry is never on the JustOne fast path while captures are active (Interest::and(never, always) == sometimes, decided per thread by enabled()).
  • Add an isolated deterministic regression: a scopeless std::thread first-executes a warn callsite reserved for the test, then the capturing thread re-emits the same callsite and asserts it was captured. It fails on the previous tree (reproduced in isolation) and passes with the guard.
  • No retries, no suppressions, no whole-suite serialization, no product-code change.

Evidence

Check Result
Regression isolated, pre-fix (guard disabled) FAILED (event dropped)
Regression isolated, with fix passed
Full backend suite, disposable DB, 50 consecutive parallel runs (237 tests each, 0 ignored) 0 SEC-04 capture failures (baseline before fix: 5/15 runs failed)
Negative control: raw provider body + raw payload temporarily logged both SEC-04 content tests failed with the markers, unmutated invalid_json test still passed; mutations reverted, tests green
cargo fmt --all --check, cargo check -p macro-tracker-backend --locked clean
Secrets scan (gitleaks git origin/staging..HEAD) no leaks

Two remaining failures over the 50 runs were the pre-existing barcode stub transport flake (all_genuine_misses_still_return_not_found, a_successful_fallback_wins_over_an_outage: 503 vs 200, no log capture involved) — explicitly out of scope and not bundled here.

App version stays 3.6.0: test-only change, no feature behavior.

…oisoning

tracing-core caches Interest per callsite process-wide. While at most one dispatcher has ever been registered, a first hit is resolved from the registering thread's default subscriber, so a parallel no-subscriber test thread could cache Interest::never for upstream_photo_failure and silently drop the captured warn events (SEC-04 flake). Register one permanent no-op dispatcher so the registry stays on the multi-dispatcher path. Add an isolated deterministic regression that fails without it.
@lnieuwenhuis
lnieuwenhuis merged commit 5a40861 into staging Sep 17, 2026
7 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant