diff --git a/assert/assertions.go b/assert/assertions.go index 558201ff5..de7e72a2a 100644 --- a/assert/assertions.go +++ b/assert/assertions.go @@ -2010,14 +2010,29 @@ func Eventually(t TestingT, condition func() bool, waitFor time.Duration, tick t h.Helper() } - const failed = 0 - const stop = 1 - const noStop = 2 - - resultCh := make(chan int, 1) + // ResultTimeout is the original message when a timeout happens. + const ResultTimeout = "Condition never satisfied" + // ResultFailed means the condition function called require.Fail or similar. + const ResultFailed = "Condition failed" + // ResultPanic means the condition function panicked. + const ResultPanic = "Condition panicked" + + // "start" and "stop" are non-error result values from the condition function + const stop = "Condition satisfied" + const noStop = "Condition not satisfied" + + resultCh := make(chan string, 1) checkCond := func() { - result := failed + result := ResultFailed defer func() { + // A panic goes a different route that a failed test. + // We can distinguish them here and add the recover() result as detailed info. + // This is similar to what happens with a real panic in a test but allows us + // to stop the test gracefully. + if r := recover(); r != nil { + t.Errorf("Panic in condition: %v\n%s", r, debug.Stack()) + result = ResultPanic + } resultCh <- result }() if condition() { @@ -2042,23 +2057,23 @@ func Eventually(t TestingT, condition func() bool, waitFor time.Duration, tick t for { select { case <-timer.C: - return Fail(t, "Condition never satisfied", msgAndArgs...) + return Fail(t, ResultTimeout, msgAndArgs...) case <-tickC: tickC = nil // Do not check again until we get a result. go checkCond() // Schedule the next check. case v := <-resultCh: switch v { - case failed: + case ResultFailed, ResultPanic: // Condition panicked or test failed and finished. // Cannot determine correct result. // Cannot decide if we should continue gracefully or not. - // We can stop here and now, and mark test as failed with + // We can stop here and now, and mark test as finally failed with // the same error message as the timeout case. - return Fail(t, "Condition never satisfied", msgAndArgs...) + return FailNow(t, v, msgAndArgs...) case stop: - return true + return true // Condition satisfied. case noStop: - fallthrough + fallthrough // Condition not satisfied yet, continue waiting. default: tickC = ticker.C // Enable ticks to check again. } @@ -2099,12 +2114,12 @@ func (*CollectT) Copy(TestingT) { } func (c *CollectT) fail() { - if !c.failed() { + if !c.Failed() { c.errors = []error{} // Make it non-nil to mark a failure. } } -func (c *CollectT) failed() bool { +func (c *CollectT) Failed() bool { return c.errors != nil } @@ -2164,7 +2179,7 @@ func EventuallyWithT(t TestingT, condition func(collect *CollectT), waitFor time tickC = nil go checkCond() case collect := <-ch: - if !collect.failed() { + if !collect.Failed() { return true } // Keep the errors from the last ended condition, so that they can be copied to t if timeout is reached. diff --git a/require/requirements_test.go b/require/requirements_test.go index 7cb63a554..e1c10fb35 100644 --- a/require/requirements_test.go +++ b/require/requirements_test.go @@ -3,6 +3,11 @@ package require import ( "encoding/json" "errors" + "fmt" + "os" + "os/exec" + "regexp" + "strings" "testing" "time" @@ -26,6 +31,7 @@ type AssertionTesterNonConformingObject struct { } type MockT struct { + // Failed marks the test as failed. Failed bool } @@ -788,3 +794,158 @@ func TestEventuallyWithTTrue(t *testing.T) { False(t, mockT.Failed, "Check should pass") Equal(t, 2, counter, "Condition is expected to be called 2 times") } + +func TestFailInsideEventuallyViaCommandLine(t *testing.T) { + t.Setenv("TestFailInsideEventually", "1") + cmd := exec.Command("go", "test", "-v", "-race", "-count=1", "-run", "^TestFailInsideEventually$") + out, err := cmd.CombinedOutput() + assert.Error(t, err, "go test for TestFailInsideEventually must fail") + finishedTests := 0 + observedErrors := 0 + observedConditionFailures := 0 + observedPanics := 0 + extractTestNameExp := regexp.MustCompile(`TestFailInsideEventuallyViaCommandLine[^ ]*`) + name := "" + for _, line := range strings.Split(string(out), "\n") { + line = strings.TrimSpace(line) + if strings.HasPrefix(line, "=== RUN ") { + name = extractTestNameExp.FindString(line) + fmt.Println(line) + } + + if strings.Contains(line, "❌") { + fmt.Println(name, line, "<-- unexpected error") + observedErrors++ + } + if strings.Contains(line, "✅ FINISHED") { + fmt.Println(name, line, "<-- expected successful test") + finishedTests++ + } + if strings.Contains(line, "Error:") && strings.Contains(line, "Condition") { + fmt.Println(name, line, "<-- expected 'Condition' message") + observedConditionFailures++ + } + if strings.Contains(line, "Panic in condition:") { + fmt.Println(name, line, "<-- expected panic message") + observedPanics++ + } + } + + assert.Equal(t, 0, observedErrors, "Unexpected errors detected, see output") + + // There are 6 tests that are expected to fail. + // If you change the number of tests in TestFailInsideEventually, please update this number accordingly. + assert.Equal(t, 6, finishedTests, "Expected number of FINISHED tests not found") + + // There are 5 tests where the condition is never satisfied. + // One test uses assert.Fail but eventually returns true and thus satisfies the condition. + // If you change the number of tests in TestFailInsideEventually, please update this number accordingly. + assert.Equal(t, 5, observedConditionFailures, "Expected number of 'Condition' messages not found, see output") + + // There are 2 tests that panic, so we expect 2 panic messages. + assert.Equal(t, 2, observedPanics, "Missed expected panics, see output") +} + +func TestFailInsideEventually(t *testing.T) { + if os.Getenv("TestFailInsideEventually") == "" { + t.Skip("Skipping test, run via TestFailInsideEventuallyViaCommandLine") + } + + // Using testing.T: + // Enable this test temporarily to manually check that the issue is fixed. + // Note that MockT does not reproduce the issue, so we have to use the real *testing.T. + // TODO: Enhance MockT to reproduce the issue, then we can remove the t.Skip above. + // UPDATE: I tried to enhance MockT, but it still does not reproduce the issue or fails + // in a different way. Therefore I keep using *testing.T for now. + // In general, require.MockT does not play well when assert.Fail is called. + // The test will not be marked as failed, even though Fail is called. + + // The Bug: + // Calling require.Fail (or similar) inside require.Eventually will prevent the 'condition' + // to exit with a result. The channel assignment in the assert.Eventually will block + // and hang the test until the timeout is reached. There was is no other way to wait + // for the unclean exit. The changes to assert.Eventually committed with this test + // fix this issue, by also waiting for an unclean exit of the condition and moreover + // by handling panics inside the condition gracefully. + + // How to read the test results: + // - See [TestFailInsideEventuallyViaCommandLine], which automates this + // - The test will always fail, because it calls Fail or assert.Fail or panics + // - The test is "successful" if it fails quickly and cleanly, i.e. without + // multiple calls to the eventually function, except if expected. + // - The test logs should contain specific messages, see below. + // - The test must not log any UNCLEAN EXIT or MISSED ASSERTIONS messages or any errors ❌. + + type test struct { + Name string + Return bool + FailFunc func(t TestingT) + MustStop bool // after the FailFunc is called + } + + const returnStop = true + const returnNoStop = false + const mustStop = true + const mustNotStop = false + + RequireFail := func(t TestingT) { Fail(t, "💥 fail now") } + AssertFail := func(t TestingT) { assert.Fail(t, "💥 mark as failed") } + Panic := func(_ TestingT) { panic("💥 panicking now") } + + for _, tt := range []test{ + // Test cases that must exit immediately after the first call to the condition. + {"require.Fail must stop", returnStop, RequireFail, mustStop}, + {"require.Fail must stop even if told not to", returnNoStop, RequireFail, mustStop}, + {"assert.Fail must stop if told to", returnStop, AssertFail, mustStop}, + + // The following test case is the only one that must not stop and where multiple calls + // to the condition are expected, because assert.Fail does not stop the execution of the condition. + {"assert.Fail must not stop if told not to", returnNoStop, AssertFail, mustNotStop}, + + // Panics must always stop, because they are not expected and indicate a bug in the code. + {"panic must stop", returnStop, Panic, mustStop}, + {"panic must stop even if told not to", returnNoStop, Panic, mustStop}, + + // Make sure to update the assertions in TestFailInsideEventuallyViaCommandLine + // accordingly if you change the number of tests here. + } { + count := 0 + start := time.Now() + timeout := time.Second * 1 + tick := time.Second / 3 + ok := false + + ok = t.Run(tt.Name, func(t *testing.T) { + // Cannot use a MockT here, because it does reproduce the issue. + Eventually(t, func() bool { + count++ + t.Log("🪲 eventually call number:", count, "calling FailNow!") + tt.FailFunc(t) // any case that calls Fail or assert.Fail should stop retrying + return tt.Return // indicate whether to stop retrying + }, timeout, tick) + }) + + dur := time.Since(start) + t.Log("🪲 test duration:", dur) + + // TODO: Replace with plain t with MockT once it can reproduce the issue. + // Until can only indicate that the test should have failed using stdout. + + c := new(assert.CollectT) + assert.True(c, !ok, "❌ UNCLEAN EXIT: test was expected to fail, but passed") + + if tt.MustStop { + assert.Equal(c, 1, count, "❌ UNCLEAN EXIT: eventually func should be called exactly once") + assert.Less(c, dur, tick, "❌ UNCLEAN EXIT: eventually func should be called only once, but took too long") + } else { + assert.Greater(c, count, 1, "❌ MISSED ASSERTIONS: eventually func should be called multiple times, but was called only once") + assert.Greater(c, dur, tick, "❌ MISSED ASSERTIONS: eventually func should be called multiple times over time, but total duration was too short") + } + + if c.Failed() { + t.Log("❌ TEST FAILED") + } else { + t.Log("✅ FINISHED", tt.Name) + } + } +}