Skip to content

Flaky: test_nwbiterator_unit_system loses the final chunk to a shutdown race #17

Description

@cboulay

Symptom

tests/test_integration.py::test_nwbiterator_unit_system intermittently fails on CI with one chunk missing:

    total_samples = sum(m.data.shape[0] for m in messages)
>   assert total_samples == 3000
E   assert 2000 == 3000

Seen on build (3.12, ubuntu-latest) in this run. Re-running the identical commit (7d8e7c8) turned all 13 jobs green, so it is timing, not code. It has failed on dev before now.

Note the six sibling jobs in that run report failure only because of fail-fast — their logs read 170 passed followed by The operation was canceled. Only the one job actually failed, which makes this easy to over-read when scanning the checks list.

Why the numbers name the cause

Broadband is 3000 samples at 1 kHz, and the test sets chunk_dur=1.0 — three chunks of 1000. 2000 is the last chunk missing, never a partial one.

NWBIteratorUnit.produce raises NormalTermination on the line after it yields that final chunk:

https://github.com/ezmsg-org/ezmsg-nwb/blob/dev/src/ezmsg/nwb/reader.py#L18-L32

So the last message is still in flight when the graph begins tearing down, and whether MessageLogger flushes it before shutdown completes is a race. The test asserts an exact total, so it silently depends on winning that race — on a loaded CI runner it sometimes doesn't.

Ruled out

  • Cross-worker temp-file collision. The log filenames under tempfile.gettempdir() are distinct per test, and --dist=loadfile pins same-file tests to one worker.
  • Anything in the ASCII-decoding change (Decode HDF5 text that its writer declared ASCII #16), where this first surfaced. Broadband is float32, so that PR's _is_bytes_text returns False and dset is child.data unchanged; its ch-label change yields the same U-dtype array. Nothing it adds runs per chunk.

Not reproducible locally

macOS, 12/12 serial and 10/10 under xdist. It needs CI's timing.

Suggested fix

Let the sink drive shutdown instead of racing the source's exhaustion — TerminateOnTotal is already imported in test_integration.py. That makes the message count the termination condition rather than something asserted after an unsynchronized teardown.

Worth a look at whether NormalTermination is expected to guarantee delivery of already-yielded messages. If it is, this is an ezmsg bug rather than a test bug, and every self-terminating source in the wild can drop its tail — which would matter well beyond this test.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions