Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
45 changes: 30 additions & 15 deletions assert/assertions.go
Original file line number Diff line number Diff line change
Expand Up @@ -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() {
Expand All @@ -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...)
Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same message as before

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...)
Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

two new messages, since these are two new ways of aborting the eventually

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.
}
Expand Down Expand Up @@ -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 {
Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be OK to expose, since it is a very std. method and provides utility in tests where you want to reason on the collect status.

If not desired, I can track tests errors in another variable.
See new(assert.CollectT) further below, where I use it.

return c.errors != nil
}

Expand Down Expand Up @@ -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.
Expand Down
161 changes: 161 additions & 0 deletions require/requirements_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,11 @@ package require
import (
"encoding/json"
"errors"
"fmt"
"os"
"os/exec"
"regexp"
"strings"
"testing"
"time"

Expand All @@ -26,6 +31,7 @@ type AssertionTesterNonConformingObject struct {
}

type MockT struct {
// Failed marks the test as failed.
Failed bool
}

Expand Down Expand Up @@ -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$")
Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Another clean alternative would be to store the log output from the always failing test as test fixure. And only analyze the fixure here.

The fixure can be create are part of the code gen.

I am not sure we can easily extend MockT to reproduce this.

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)
}
}
}