From 2f8f51724ad2a3509603d53d8a850f9146e4016f Mon Sep 17 00:00:00 2001 From: "Bryan C. Mills" Date: Tue, 10 Jan 2023 12:59:16 -0500 Subject: [PATCH] cmd/go/internal/lockedfile: avoid failing tests due to arbitrary timeouts MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit The mustBlock helper returns a function that verifies that the blocked operation does eventually complete. However, it used an arbitrary 10-second timeout in place of “eventually”. Since the test is checking a synchronization library, bugs are likely to manifest as deadlocks. It may be useful to log what operation is in flight if such a deadlock occurs; however, since we can't bound how long a “reasonable” operation should take, the log message should only be informational — it should not cause the test to fail. While we're here, let's also set a better example by not leaking time.After timers in the tests.. Fixes #57592. Change-Id: I4e74e42390679bffac7a286824acb71b08994c17 Reviewed-on: https://go-review.googlesource.com/c/go/+/461000 Reviewed-by: Damien Neil TryBot-Result: Gopher Robot Run-TryBot: Bryan Mills Auto-Submit: Bryan Mills --- .../go/internal/lockedfile/lockedfile_test.go | 33 ++++++++++++++----- 1 file changed, 24 insertions(+), 9 deletions(-) diff --git a/src/cmd/go/internal/lockedfile/lockedfile_test.go b/src/cmd/go/internal/lockedfile/lockedfile_test.go index 5f6153cb15..6b54654ac7 100644 --- a/src/cmd/go/internal/lockedfile/lockedfile_test.go +++ b/src/cmd/go/internal/lockedfile/lockedfile_test.go @@ -43,19 +43,32 @@ func mustBlock(t *testing.T, desc string, f func()) (wait func(*testing.T)) { close(done) }() + timer := time.NewTimer(quiescent) + defer timer.Stop() select { case <-done: t.Fatalf("%s unexpectedly did not block", desc) - return nil + case <-timer.C: + } + + return func(t *testing.T) { + logTimer := time.NewTimer(quiescent) + defer logTimer.Stop() - case <-time.After(quiescent): - return func(t *testing.T) { + select { + case <-logTimer.C: + // We expect the operation to have unblocked by now, + // but maybe it's just slow. Write to the test log + // in case the test times out, but don't fail it. t.Helper() - select { - case <-time.After(probablyStillBlocked): - t.Fatalf("%s is unexpectedly still blocked after %v", desc, probablyStillBlocked) - case <-done: - } + t.Logf("%s is unexpectedly still blocked after %v", desc, quiescent) + + // Wait for the operation to actually complete, no matter how long it + // takes. If the test has deadlocked, this will cause the test to time out + // and dump goroutines. + <-done + + case <-done: } } } @@ -244,10 +257,12 @@ locked: if _, err := os.Stat(filepath.Join(dir, "locked")); !os.IsNotExist(err) { break locked } + timer := time.NewTimer(1 * time.Millisecond) select { case <-qDone: + timer.Stop() break locked - case <-time.After(1 * time.Millisecond): + case <-timer.C: } } -- 2.50.0