Skip to content

Coordinate threading tests with events instead of sleeps - #1499

Open
arose26 wants to merge 1 commit into
Delgan:masterfrom
arose26:threading-tests-without-sleep
Open

Coordinate threading tests with events instead of sleeps#1499
arose26 wants to merge 1 commit into
Delgan:masterfrom
arose26:threading-tests-without-sleep

Conversation

@arose26

@arose26 arose26 commented Aug 17, 2026

Copy link
Copy Markdown

Closes #1467

Four tests in tests/test_threading.py used time.sleep(0.5) to land an operation in the middle of a slow sink's write. That ordering only holds while the machine keeps up, which is the concern raised in the issue — and free-threaded builds make it less safe still.

The sleeps are replaced with events that the sink sets itself, so the second thread proceeds exactly when the first is mid-operation rather than after a fixed delay.

NonSafeSink gains two events:

  • writing — set after the first half of the message is written, immediately before the sink's simulated I/O delay
  • stopping — set on entry to stop(), and shareable between sinks so a test can wait for the first of a group to begin stopping

The sink's own time.sleep(self.sleep_time) / time.sleep(self.stop_time) stay: those are the simulated slow I/O being tested, not coordination.

Why not the version proposed in the issue

As you pointed out, waiting for logger.info() to finish would make the threads sequential and stop testing the interleaving. These events fire while the sink is still inside its delay, so logger.add() / logger.remove() still happen in parallel with an in-flight write — the same window sleep(0.5) was aiming at, without depending on the clock.

Per test:

test previously now
test_safe_adding_while_logging sleep(0.5) sink_1.writing.wait()
test_safe_removing_while_logging sleep(0.5) sink.writing.wait()
test_safe_slow_removing_all_while_logging sleep(0.5) shared stopping.wait() across the ten sinks
test_safe_writing_after_removing sleep(0.5) sink_1.writing.wait()

The last one needed a shared event because logger.remove() tears down ten sinks and which one stops first is not guaranteed; waiting on any single sink would reintroduce an assumption.

Notes

Runtime is unchanged (~15s for the file). The removed sleeps overlapped the sinks' own delays, so this buys determinism rather than speed — worth saying since faster execution came up in the issue.

tests/test_threading.py passes, repeated three times to check for flakiness. ruff check and black --check are clean.

The tests relied on sleeping half a second to land an operation in the
middle of a slow sink, which only holds while the machine keeps up.
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.

Time-based coordination in unit test may not guarantee thread orderings

1 participant