Wait for conditions in tests instead of sleeping for a guess - #48
Merged
Merged
Conversation
A fixed sleep before asserting on another thread's work is wrong in both directions at once. It is too long whenever the work is already done, which it almost always is; and too short whenever the machine is loaded, which is when CI runs -- and then the failure arrives as an assertion about logging or statistics that says nothing about timing. Await polls instead: it returns as soon as the condition holds, and can afford a timeout generous enough for a slow runner because that cost is only paid when the test is genuinely failing. Most of the 70-odd Thread.sleep calls in this suite were already fine and are untouched: bounded poll loops that break on a condition, and "hold the socket open" sleeps on fake-server threads, which cost no wall time because the pool is shut down when the test ends. ForwarderBodyLoggingTest already polled with a deadline. What changed is the nine unconditional waits before an assertion. InsightServerTest was the concentration: 5.5 of its 6.3 seconds were sleep, and it went to 0.6. Two other things surfaced while fixing it, and they are the same defect seen from different angles. It never stopped the servers it started, so it leaked one per test -- the bug already fixed in HealthEndpointsTest, whose sibling went unchecked at the time. And seven tests hardcoded ports 8993-8999, which is not an unrelated smell but a symptom: each test needed a *different* fixed port precisely because the previous test's server still held the last one. Stopping the servers makes TestPorts.free() usable throughout, and removes a flake that would have read as an unexplained bind failure. HealthEndpointsTest had a second, separately-constructed server that also went unstopped. Not everything can be polled. Asserting something did *not* happen has to give it time to happen first, and there is no condition that becomes true: ProxyLoopTest, SchedulerTest's two post-cancel checks, and the "logs nothing" cases keep their sleeps and now say why. For those, too short weakens the test rather than flaking it, which is the opposite failure mode and worth naming. ForwarderLoggingTest's helper serves both kinds, so Await.atMost returns as soon as a line appears and otherwise waits the full window, without the helper having to know which caller it has. 954 tests, unchanged; the eight affected classes run clean three times over.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
The last outstanding item from the Codex audit's test-suite list.
Of ~70
Thread.sleepcalls, most were already correct and are untouched: boundedpoll loops that break on a condition, and "hold the socket open" sleeps on
fake-server threads, which cost no wall time because the pool is shut down when the
test ends.
ForwarderBodyLoggingTestalready polled against a deadline.Nine were real, and they split into two kinds with opposite failure modes:
poll via a new
Awaithelper, which returns as soon as the condition holds andcan afford a generous timeout because that cost is only paid when failing.
rather than breaking it.
ProxyLoopTest,SchedulerTest's two post-cancelchecks and the "logs nothing" cases cannot poll, since no condition ever becomes
true. They keep their sleeps and now say why.
ForwarderLoggingTest's helper serves both kinds, soAwait.atMostreturns earlywhen a line appears and otherwise waits the full window.
InsightServerTest
6.28s to 0.64s. Two things surfaced while fixing it, and they are one defect seen
twice:
already fixed in
HealthEndpointsTest, whose sibling went unchecked at the time.test needed a different fixed port because the previous test's server still held
the last one.
Fixing the leak makes
TestPorts.free()usable throughout and removes a flake thatwould have read as an unexplained bind failure.
HealthEndpointsTestalso had asecond, separately-constructed server that went unstopped.
Results
954 tests, unchanged.
HttpLoggingTest2.91s to 1.12s. The eight affected classesrun clean three times over.
The wall-time saving is ~8-9s against a 170s suite, about 5% — modest. The real
gain is that these tests no longer depend on a guess about how fast the machine is.