Levandor

py-mando Logger Init Race Flaky Test

3 min read

Intermittent CI failure of test_dd_conformance.py::test_init_populates_identity_and_dd_env in py-mando, root-caused to leaked background Axum server threads (spawned merely by constructing AlgoRunner) racing a non-thread-safe logger.init(). A threading.Lock mitigation shipped on develop (MR !601), but it is not a proven 100% fix.

For Agents

This is a shared-mutable-state cross-test race, same bug CLASS as the env-var flakes in mando-known-flaky-tests-2026-07-15. The shipped Lock narrows the window by orders of magnitude but a residual microsecond window remains. Do NOT treat the flake as fully closed; the real fix (stop leaking server threads / stop asserting on module globals) needs its own ticket.

Symptom

assert lg.identity["service"] == "bess-os-algo-optimization"
# fails: identity["service"] is None
  • Intermittent, timing-dependent. Passes on retry.
  • Seen on develop @ ab4c54c1 (pipeline 2746786029); can hit any branch carrying the DD-conformance suite.
  • Tell: the log lines Starting Algo runner service, listening on 127.0.0.1:3003 and .../3002 appear interleaved right before the failing test. Those are the leaked AlgoRunner server threads emitting.

Root cause

A chain of three defects across the Rust/Python boundary:

  1. Construction spawns a permanent thread. py-mando/src/algo_runner.rs AlgoRunner::new (around line 113) does std::thread::spawn(... start_server ...). Just constructing an AlgoRunner launches a background Axum server thread. Its graceful shutdown only fires on Ctrl+C / SIGTERM, so inside pytest it never stops.
  2. start_server re-inits the logger with no service arg. start_server calls init_logger(py), which calls Python py_mando.logger.init() with no service argument (service defaults to None).
  3. logger.init() is not thread-safe. py-mando/python/py_mando/logger.py init() sets the global identity on one line, but only sets _initialized = True several slow lines later — the gap includes import ddtrace.auto. That is a wide race window.

test_algo_runner.py constructs AlgoRunner twice (test_algo_runner_creation on port 3002, test_algo_runner_run_method on port 3003) and leaks both server threads. Their init() calls fire asynchronously during the LATER test_dd_conformance run. A background init() (service=None) landing inside the window overwrites identity with {"service": None, ...}, so the assertion sees None.

Two module globals (identity, _initialized) mutated by leaked background threads, plus a test that resets _initialized = False, equals a shared-state collision.

Mitigation shipped (not a guaranteed fix)

  • What: a double-checked threading.Lock around the body of logger.init().
  • Where: merged to develop via MR !601, branch feature/BE-4067, commit fix: guard py-mando logger init against concurrent initialization.
  • Effect: closes the WIDE window (the slow ddtrace import) and cuts flake probability by orders of magnitude.

Not a proven 100% fix

A residual microsecond window remains: a background init() in-flight at the instant test_dd_conformance resets _initialized still loses. Treat the flake as heavily reduced, not eliminated.

Real 100% fix (needs its own ticket)

Remove the shared-state collision at the source. Either:

  • AlgoRunner should not spawn an unstoppable server thread just to be constructed, or
  • test_dd_conformance should not assert on module globals that live background threads mutate — isolate via a local monkeypatch of identity / _initialized, or run the test in a fresh process.

Merge / rebase gotcha observed

MR !601’s diff previewed conflicts in opl.rs and ts_data_retrieve.rs (via git merge-tree), but git rebase origin/develop resolved them automatically by dropping 5 branch commits as “patch contents already upstream”. Those error-unwalling commits had already reached develop through another MR. merge-tree previews such conflicts as real; rebase recognises the duplicate patches and drops them. Lesson: a merge-tree conflict preview is not proof of a real rebase conflict when the branch’s commits may already be upstream.

Graph View

Backlinks