john/McRogueFace

Fork 0

[Bugfix] Flaky suite failure: OpenAL-soft asserts during device teardown (snippets/253_Music.py) #400

New issue

Open

opened 2026-07-27 03:46:48 +00:00 by john · 1 comment

john commented

2026-07-27 03:46:48 +00:00

Owner

Summary

tests/snippets/253_Music.py fails intermittently — roughly 1 run in 3 — after the snippet itself has completed successfully. Not a test-logic bug; a shutdown race in the system OpenAL library.

Evidence

Failing run's captured output (python3 run_tests.py snippets -v):

Duration: 0.6396819949150085s
Playing: True
SNIPPET_OK: scene='music_demo' children=1
AL lib: (EE) alc_cleanup: 1 device not closed
mcrogueface: /build/openal-soft-ib3XZ4/openal-soft-1.19.1/Alc/ALc.c:800: LockLists: Assertion `ret == althrd_success' failed.

SNIPPET_OK is the harness's success marker, so every assertion the snippet makes has already passed. The abort happens afterwards, in alc_cleanup at process teardown, and the resulting non-zero exit is what run_tests.py scores as a failure.

Observed 3 times across 6 consecutive run_tests.py snippets invocations (passing and failing runs interleaved with no source changes between them).

Notes

AL lib: (EE) alc_cleanup: 1 device not closed prints on every engine shutdown, including clean ones — the engine leaves an ALC device open at exit. That is the precondition; the assert is the intermittent consequence.
OpenAL-soft 1.19.1 (Debian). LockLists asserting althrd_success at teardown is a known class of race in that vintage.
Same flavour as the known-flaky benchmark_logging_test (passes standalone, fails in-suite) — both are teardown-order artifacts rather than behavioural failures.

Possible directions

Close the ALC device explicitly during engine shutdown so alc_cleanup has nothing left to race on — this would also silence the unconditional (EE) line, which currently trains everyone to ignore engine stderr.
Failing that, treat a post-SNIPPET_OK abort as a non-failure in the runner — but that hides real teardown crashes, so (1) is much preferable.

#380 — shipped artifacts gated by nothing (the snippets suite is the gate in question)

## Summary `tests/snippets/253_Music.py` fails intermittently — roughly 1 run in 3 — **after** the snippet itself has completed successfully. Not a test-logic bug; a shutdown race in the system OpenAL library. ## Evidence Failing run's captured output (`python3 run_tests.py snippets -v`): ``` Duration: 0.6396819949150085s Playing: True SNIPPET_OK: scene='music_demo' children=1 AL lib: (EE) alc_cleanup: 1 device not closed mcrogueface: /build/openal-soft-ib3XZ4/openal-soft-1.19.1/Alc/ALc.c:800: LockLists: Assertion `ret == althrd_success' failed. ``` `SNIPPET_OK` is the harness's success marker, so every assertion the snippet makes has already passed. The abort happens afterwards, in `alc_cleanup` at process teardown, and the resulting non-zero exit is what `run_tests.py` scores as a failure. Observed 3 times across 6 consecutive `run_tests.py snippets` invocations (passing and failing runs interleaved with no source changes between them). ## Notes - `AL lib: (EE) alc_cleanup: 1 device not closed` prints on **every** engine shutdown, including clean ones — the engine leaves an ALC device open at exit. That is the precondition; the assert is the intermittent consequence. - OpenAL-soft 1.19.1 (Debian). `LockLists` asserting `althrd_success` at teardown is a known class of race in that vintage. - Same flavour as the known-flaky `benchmark_logging_test` (passes standalone, fails in-suite) — both are teardown-order artifacts rather than behavioural failures. ## Possible directions 1. Close the ALC device explicitly during engine shutdown so `alc_cleanup` has nothing left to race on — this would also silence the unconditional `(EE)` line, which currently trains everyone to ignore engine stderr. 2. Failing that, treat a post-`SNIPPET_OK` abort as a non-failure in the runner — but that hides real teardown crashes, so (1) is much preferable. ## Related - #380 — shipped artifacts gated by nothing (the snippets suite is the gate in question)

john added the

priority:tier2-foundation

Bugfix

system:documentation

labels

2026-07-27 03:46:48 +00:00

john commented

2026-07-27 07:46:50 +00:00

Author

Owner

Independently reproduced and quantified, and confirmed not caused by the frame-lock change in 1523533 (#398).

Direct invocation, 30 runs each, same box, back to back:

binary	`LockLists` assertion aborts
pre-fix `GameEngine.cpp` (as at `b77aeec`)	11 / 30
post-fix (`1523533`)	12 / 30

Statistically indistinguishable — ~37–40%, consistent with the "roughly 1 in 3" in the issue body. The abort is unaffected by the change, so it is pre-existing.

Two details worth recording:

SNIPPET_OK / the snippet's own prints always appear before the abort. The failure is entirely in alc_cleanup at process teardown.
The AL lib: (EE) alc_cleanup: 1 device not closed line appears on all 60 runs, aborting or not. It is the precondition, not the symptom, exactly as the issue says — which supports resolution (1): close the ALC device explicitly at shutdown.

Practical impact today: a full run_tests.py has a ~40% chance of scoring one spurious failure on this snippet. Two consecutive full-suite runs during #398's verification happened to come up clean (625/625 and 624/624 with --exclude=packaging), so a green suite is not evidence the race is gone.

Independently reproduced and quantified, and confirmed **not** caused by the frame-lock change in `1523533` (#398). Direct invocation, 30 runs each, same box, back to back: | binary | `LockLists` assertion aborts | |---|---| | pre-fix `GameEngine.cpp` (as at `b77aeec`) | **11 / 30** | | post-fix (`1523533`) | **12 / 30** | Statistically indistinguishable — ~37–40%, consistent with the "roughly 1 in 3" in the issue body. The abort is unaffected by the change, so it is pre-existing. Two details worth recording: - `SNIPPET_OK` / the snippet's own prints always appear before the abort. The failure is entirely in `alc_cleanup` at process teardown. - The `AL lib: (EE) alc_cleanup: 1 device not closed` line appears on **all 60** runs, aborting or not. It is the precondition, not the symptom, exactly as the issue says — which supports resolution (1): close the ALC device explicitly at shutdown. Practical impact today: a full `run_tests.py` has a ~40% chance of scoring one spurious failure on this snippet. Two consecutive full-suite runs during #398's verification happened to come up clean (625/625 and 624/624 with `--exclude=packaging`), so a green suite is not evidence the race is gone.

john referenced this issue

2026-07-27 15:38:05 +00:00

[Bugfix] --audio-off and config.audio_enabled are dead code: audio plays under --headless #406

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference

john/McRogueFace#400

No description provided.

Rows
Columns